All of lore.kernel.org
 help / color / mirror / Atom feed
* [1.44 00/18] Patch review
@ 2019-12-23  4:50 Armin Kuster
  2019-12-23  4:50 ` [1.44 01/18] hashserv: Add support for equivalent hash reporting Armin Kuster
                   ` (17 more replies)
  0 siblings, 18 replies; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

This series has been run on the AB.

I relize the hash work is progress for fixes to 1.44.

This is what I have so far.
The following changes since commit cfa307aabf710d79c404a8571b4158b864a94727:

  runqueue.py: not show warning for deferred multiconfig task (2019-11-29 11:26:07 +0000)

are available in the git repository at:

  git://git.openembedded.org/bitbake-contrib stable/1.44-nut
  http://cgit.openembedded.org//log/?h=stable/1.44-nut

Chris Laplante via bitbake-devel (1):
  bb.utils.fileslocked: don't leak files if yield throws

Joshua Watt (1):
  runqueue: Batch scenequeue updates

Richard Purdie (16):
  hashserv: Add support for equivalent hash reporting
  runqueue/siggen: Allow handling of equivalent hashes
  runqueue: Add extra debugging when locked sigs mismatches occur
  knotty/uihelper: Switch from pids to tids for Task event management
  siggen: Avoid taskhash mismatch errors for nostamp tasks when
    dependencies rehash
  siggen: Ensure new unihash propagates through the system
  siggen: Fix performance issue in get_unihash
  runqueue: Rework process_possible_migrations() to improve performance
  runqueue: Fix task mismatch failures from incorrect logic
  siggen: Split get_tashhash for performance
  runqueue: Fix sstate task iteration performance
  runqueue: Optimise task migration code slightly
  runqueue: Optimise out pointless loop iteration
  runqueue: Optimise task filtering
  runqueue: Only call into the migrations function if migrations active
  lib/bb: Optimise out debug messages from cooker

 lib/bb/__init__.py     |   5 ++
 lib/bb/build.py        |  25 +++++-----
 lib/bb/runqueue.py     | 127 ++++++++++++++++++++++++++++---------------------
 lib/bb/siggen.py       |  74 ++++++++++++++++++++++------
 lib/bb/ui/knotty.py    |  12 ++---
 lib/bb/ui/uihelper.py  |  39 +++++++++------
 lib/bb/utils.py        |   9 ++--
 lib/hashserv/client.py |   8 ++++
 lib/hashserv/server.py |  36 ++++++++++++++
 9 files changed, 231 insertions(+), 104 deletions(-)

-- 
2.7.4



^ permalink raw reply	[flat|nested] 22+ messages in thread

* [1.44 01/18] hashserv: Add support for equivalent hash reporting
  2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
@ 2019-12-23  4:50 ` Armin Kuster
  2019-12-23  4:50 ` [1.44 02/18] runqueue/siggen: Allow handling of equivalent hashes Armin Kuster
                   ` (16 subsequent siblings)
  17 siblings, 0 replies; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

From: Richard Purdie <richard.purdie@linuxfoundation.org>

The reason for this should be recorded in the commit logs. Imagine
you have a target recipe (e.g. meta-extsdk-toolchain) which depends on
gdb-cross. sstate in OE-Core allows gdb-cross to have the same hash
regardless of whether its built on x86 or arm. The outhash will be
different.

We need hashequiv to be able to adapt to the prescence of sstate artefacts
for meta-extsdk-toolchain and allow the hashes to re-intersect, rather than
trying to force a rebuild of meta-extsdk-toolchain. By this point in the build,
it would have already been installed from sstate so the build needs to adapt.

Equivalent hashes should be reported to the server as a taskhash that
needs to map to an specific unihash. This patch adds API to the hashserv
client/server to allow this.

[Thanks to Joshua Watt for help with this patch]

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
(cherry picked from commit 674692fd46a7691a1de59ace6af0556cc5dd6a71)
---
 lib/hashserv/client.py |  8 ++++++++
 lib/hashserv/server.py | 36 ++++++++++++++++++++++++++++++++++++
 2 files changed, 44 insertions(+)

diff --git a/lib/hashserv/client.py b/lib/hashserv/client.py
index f659566..ae0cce9 100644
--- a/lib/hashserv/client.py
+++ b/lib/hashserv/client.py
@@ -148,6 +148,14 @@ class Client(object):
         m['unihash'] = unihash
         return self.send_message({'report': m})
 
+    def report_unihash_equiv(self, taskhash, method, unihash, extra={}):
+        self._set_mode(self.MODE_NORMAL)
+        m = extra.copy()
+        m['taskhash'] = taskhash
+        m['method'] = method
+        m['unihash'] = unihash
+        return self.send_message({'report-equiv': m})
+
     def get_stats(self):
         self._set_mode(self.MODE_NORMAL)
         return self.send_message({'get-stats': None})
diff --git a/lib/hashserv/server.py b/lib/hashserv/server.py
index 0aff776..cc7e482 100644
--- a/lib/hashserv/server.py
+++ b/lib/hashserv/server.py
@@ -143,6 +143,7 @@ class ServerClient(object):
             handlers = {
                 'get': self.handle_get,
                 'report': self.handle_report,
+                'report-equiv': self.handle_equivreport,
                 'get-stream': self.handle_get_stream,
                 'get-stats': self.handle_get_stats,
                 'reset-stats': self.handle_reset_stats,
@@ -303,6 +304,41 @@ class ServerClient(object):
 
         self.write_message(d)
 
+    async def handle_equivreport(self, data):
+        with closing(self.db.cursor()) as cursor:
+            insert_data = {
+                'method': data['method'],
+                'outhash': "",
+                'taskhash': data['taskhash'],
+                'unihash': data['unihash'],
+                'created': datetime.now()
+            }
+
+            for k in ('owner', 'PN', 'PV', 'PR', 'task', 'outhash_siginfo'):
+                if k in data:
+                    insert_data[k] = data[k]
+
+            cursor.execute('''INSERT OR IGNORE INTO tasks_v2 (%s) VALUES (%s)''' % (
+                ', '.join(sorted(insert_data.keys())),
+                ', '.join(':' + k for k in sorted(insert_data.keys()))),
+                insert_data)
+
+            self.db.commit()
+
+            # Fetch the unihash that will be reported for the taskhash. If the
+            # unihash matches, it means this row was inserted (or the mapping
+            # was already valid)
+            row = self.query_equivalent(data['method'], data['taskhash'])
+
+            if row['unihash'] == data['unihash']:
+                logger.info('Adding taskhash equivalence for %s with unihash %s',
+                                data['taskhash'], row['unihash'])
+
+            d = {k: row[k] for k in ('taskhash', 'method', 'unihash')}
+
+        self.write_message(d)
+
+
     async def handle_get_stats(self, request):
         d = {
             'requests': self.request_stats.todict(),
-- 
2.7.4



^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [1.44 02/18] runqueue/siggen: Allow handling of equivalent hashes
  2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
  2019-12-23  4:50 ` [1.44 01/18] hashserv: Add support for equivalent hash reporting Armin Kuster
@ 2019-12-23  4:50 ` Armin Kuster
  2019-12-23  8:25   ` Peter Kjellerstedt
  2019-12-23  4:50 ` [1.44 03/18] runqueue: Add extra debugging when locked sigs mismatches occur Armin Kuster
                   ` (15 subsequent siblings)
  17 siblings, 1 reply; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

From: Richard Purdie <richard.purdie@linuxfoundation.org>

Based on the hashserv's new ability to accept hash mappings, update runqueue
to use this through a helper function in siggen.

This addresses problems with meta-extsdk-toolchain and its dependency on
gdb-cross which caused errors when building eSDK. See the previous commit
for more details.

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
(cherry picked from commit 39098b4ba2133f4d9229a0aa4fcf4c3e1291286a)
---
 lib/bb/runqueue.py | 31 +++++++++++++++++++------------
 lib/bb/siggen.py   | 26 ++++++++++++++++++++++++++
 2 files changed, 45 insertions(+), 12 deletions(-)

diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py
index bd7f03f..a869ba5 100644
--- a/lib/bb/runqueue.py
+++ b/lib/bb/runqueue.py
@@ -2283,12 +2283,26 @@ class RunQueueExecute:
                         for dep in self.rqdata.runtaskentries[tid].depends:
                             procdep.append(dep)
                         orighash = self.rqdata.runtaskentries[tid].hash
-                        self.rqdata.runtaskentries[tid].hash = bb.parse.siggen.get_taskhash(tid, procdep, self.rqdata.dataCaches[mc_from_tid(tid)])
+                        newhash = bb.parse.siggen.get_taskhash(tid, procdep, self.rqdata.dataCaches[mc_from_tid(tid)])
                         origuni = self.rqdata.runtaskentries[tid].unihash
-                        self.rqdata.runtaskentries[tid].unihash = bb.parse.siggen.get_unihash(tid)
-                        logger.debug(1, "Task %s hash changes: %s->%s %s->%s" % (tid, orighash, self.rqdata.runtaskentries[tid].hash, origuni, self.rqdata.runtaskentries[tid].unihash))
+                        newuni = bb.parse.siggen.get_unihash(tid)
+                        # FIXME, need to check it can come from sstate at all for determinism?
+                        remapped = False
+                        if newuni == origuni:
+                            # Nothing to do, we match, skip code below
+                            remapped = True
+                        elif tid in self.scenequeue_covered or tid in self.sq_live:
+                            # Already ran this setscene task or it running. Report the new taskhash
+                            remapped = bb.parse.siggen.report_unihash_equiv(tid, newhash, origuni, newuni, self.rqdata.dataCaches)
+                            logger.info("Already covered setscene for %s so ignoring rehash (remap)" % (tid))
+
+                        if not remapped:
+                            logger.debug(1, "Task %s hash changes: %s->%s %s->%s" % (tid, orighash, newhash, origuni, newuni))
+                            self.rqdata.runtaskentries[tid].hash = newhash
+                            self.rqdata.runtaskentries[tid].unihash = newuni
+                            changed.add(tid)
+
                         next |= self.rqdata.runtaskentries[tid].revdeps
-                        changed.add(tid)
                         total.remove(tid)
                         next.intersection_update(total)
 
@@ -2307,18 +2321,11 @@ class RunQueueExecute:
                 self.pending_migrations.add(tid)
 
         for tid in self.pending_migrations.copy():
-            if tid in self.runq_running:
+            if tid in self.runq_running or tid in self.sq_live:
                 # Too late, task already running, not much we can do now
                 self.pending_migrations.remove(tid)
                 continue
 
-            if tid in self.scenequeue_covered or tid in self.sq_live:
-                # Already ran this setscene task or it running
-                # Potentially risky, should we report this hash as a match?
-                logger.info("Already covered setscene for %s so ignoring rehash" % (tid))
-                self.pending_migrations.remove(tid)
-                continue
-
             valid = True
             # Check no tasks this covers are running
             for dep in self.sqdata.sq_covered_tasks[tid]:
diff --git a/lib/bb/siggen.py b/lib/bb/siggen.py
index e19812b..edf1010 100644
--- a/lib/bb/siggen.py
+++ b/lib/bb/siggen.py
@@ -525,6 +525,32 @@ class SignatureGeneratorUniHashMixIn(object):
                 except OSError:
                     pass
 
+    def report_unihash_equiv(self, tid, taskhash, wanted_unihash, current_unihash, datacaches):
+        try:
+            extra_data = {}
+            data = self.client().report_unihash_equiv(taskhash, self.method, wanted_unihash, extra_data)
+            bb.note('Reported task %s as unihash %s to %s (%s)' % (tid, wanted_unihash, self.server, str(data)))
+
+            if data is None:
+                bb.warn("Server unable to handle unihash report")
+                return False
+
+            finalunihash = data['unihash']
+
+            if finalunihash == current_unihash:
+                bb.note('Task %s unihash %s unchanged by server' % (tid, finalunihash))
+            elif finalunihash == wanted_unihash:
+                bb.note('Task %s unihash changed %s -> %s as wanted' % (tid, current_unihash, finalunihash))
+                self.set_unihash(tid, finalunihash)
+                return True
+            else:
+                # TODO: What to do here?
+                bb.note('Task %s unihash reported as unwanted hash %s' % (tid, finalunihash))
+
+        except hashserv.client.HashConnectionError as e:
+            bb.warn('Error contacting Hash Equivalence Server %s: %s' % (self.server, str(e)))
+
+        return False
 
 #
 # Dummy class used for bitbake-selftest
-- 
2.7.4



^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [1.44 03/18] runqueue: Add extra debugging when locked sigs mismatches occur
  2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
  2019-12-23  4:50 ` [1.44 01/18] hashserv: Add support for equivalent hash reporting Armin Kuster
  2019-12-23  4:50 ` [1.44 02/18] runqueue/siggen: Allow handling of equivalent hashes Armin Kuster
@ 2019-12-23  4:50 ` Armin Kuster
  2019-12-23  4:50 ` [1.44 04/18] knotty/uihelper: Switch from pids to tids for Task event management Armin Kuster
                   ` (14 subsequent siblings)
  17 siblings, 0 replies; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

From: Richard Purdie <richard.purdie@linuxfoundation.org>

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
(cherry picked from commit 3aad9978be2a40d4c535a5ae092f374ba2a5f627)
---
 lib/bb/runqueue.py | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py
index a869ba5..246a9cd 100644
--- a/lib/bb/runqueue.py
+++ b/lib/bb/runqueue.py
@@ -2524,6 +2524,8 @@ class RunQueueExecute:
                 msg = 'Task %s.%s attempted to execute unexpectedly and should have been setscened' % (pn, taskname)
             else:
                 msg = 'Task %s.%s attempted to execute unexpectedly' % (pn, taskname)
+            for t in self.scenequeue_notcovered:
+                msg = msg + "\nTask %s, unihash %s, taskhash %s" % (t, self.rqdata.runtaskentries[t].unihash, self.rqdata.runtaskentries[t].hash)
             logger.error(msg + '\nThis is usually due to missing setscene tasks. Those missing in this build were: %s' % pprint.pformat(self.scenequeue_notcovered))
             return True
         return False
-- 
2.7.4



^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [1.44 04/18] knotty/uihelper: Switch from pids to tids for Task event management
  2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
                   ` (2 preceding siblings ...)
  2019-12-23  4:50 ` [1.44 03/18] runqueue: Add extra debugging when locked sigs mismatches occur Armin Kuster
@ 2019-12-23  4:50 ` Armin Kuster
  2019-12-23  4:50 ` [1.44 05/18] siggen: Avoid taskhash mismatch errors for nostamp tasks when dependencies rehash Armin Kuster
                   ` (13 subsequent siblings)
  17 siblings, 0 replies; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

From: Richard Purdie <richard.purdie@linuxfoundation.org>

We've seen cases where a task can execute with a given pid, complete
and a new task can start using the same pid before the UI handler has
had time to adapt.

Traceback (most recent call last):
  File "/home/pokybuild/yocto-worker/qemux86-alt/build/bitbake/lib/bb/ui/knotty.py", line 484, in main
    helper.eventHandler(event)
  File "/home/pokybuild/yocto-worker/qemux86-alt/build/bitbake/lib/bb/ui/uihelper.py", line 30, in eventHandler
    del self.running_tasks[event.pid]
KeyError: 13490

This means using pids to match up events on the UI side is a bad
idea. Change the code to use task ids instead. There is a small
amount of fuzzy matching for the progress information since there
is no task information there and we don't want the overhead of a task
ID in every event, however since pid reuse is unlikely, we can live
with a progress bar not quite working properly in a corner case like
this.

[YOCTO #13667]

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
(cherry picked from commit e427eafa1bb04008d12100ccc5c862122bba53e0)
---
 lib/bb/build.py       | 25 +++++++++++++------------
 lib/bb/ui/knotty.py   | 12 ++++++------
 lib/bb/ui/uihelper.py | 39 ++++++++++++++++++++++++---------------
 3 files changed, 43 insertions(+), 33 deletions(-)

diff --git a/lib/bb/build.py b/lib/bb/build.py
index 30a2ba2..3d9cc10 100644
--- a/lib/bb/build.py
+++ b/lib/bb/build.py
@@ -57,8 +57,9 @@ builtins['os'] = os
 class TaskBase(event.Event):
     """Base class for task events"""
 
-    def __init__(self, t, logfile, d):
+    def __init__(self, t, fn, logfile, d):
         self._task = t
+        self._fn = fn
         self._package = d.getVar("PF")
         self._mc = d.getVar("BB_CURRENT_MC")
         self.taskfile = d.getVar("FILE")
@@ -81,8 +82,8 @@ class TaskBase(event.Event):
 
 class TaskStarted(TaskBase):
     """Task execution started"""
-    def __init__(self, t, logfile, taskflags, d):
-        super(TaskStarted, self).__init__(t, logfile, d)
+    def __init__(self, t, fn, logfile, taskflags, d):
+        super(TaskStarted, self).__init__(t, fn, logfile, d)
         self.taskflags = taskflags
 
 class TaskSucceeded(TaskBase):
@@ -91,9 +92,9 @@ class TaskSucceeded(TaskBase):
 class TaskFailed(TaskBase):
     """Task execution failed"""
 
-    def __init__(self, task, logfile, metadata, errprinted = False):
+    def __init__(self, task, fn, logfile, metadata, errprinted = False):
         self.errprinted = errprinted
-        super(TaskFailed, self).__init__(task, logfile, metadata)
+        super(TaskFailed, self).__init__(task, fn, logfile, metadata)
 
 class TaskFailedSilent(TaskBase):
     """Task execution failed (silently)"""
@@ -103,8 +104,8 @@ class TaskFailedSilent(TaskBase):
 
 class TaskInvalid(TaskBase):
 
-    def __init__(self, task, metadata):
-        super(TaskInvalid, self).__init__(task, None, metadata)
+    def __init__(self, task, fn, metadata):
+        super(TaskInvalid, self).__init__(task, fn, None, metadata)
         self._message = "No such task '%s'" % task
 
 class TaskProgress(event.Event):
@@ -572,7 +573,7 @@ def _exec_task(fn, task, d, quieterr):
 
     try:
         try:
-            event.fire(TaskStarted(task, logfn, flags, localdata), localdata)
+            event.fire(TaskStarted(task, fn, logfn, flags, localdata), localdata)
         except (bb.BBHandledException, SystemExit):
             return 1
 
@@ -583,15 +584,15 @@ def _exec_task(fn, task, d, quieterr):
             for func in (postfuncs or '').split():
                 exec_func(func, localdata)
         except bb.BBHandledException:
-            event.fire(TaskFailed(task, logfn, localdata, True), localdata)
+            event.fire(TaskFailed(task, fn, logfn, localdata, True), localdata)
             return 1
         except Exception as exc:
             if quieterr:
-                event.fire(TaskFailedSilent(task, logfn, localdata), localdata)
+                event.fire(TaskFailedSilent(task, fn, logfn, localdata), localdata)
             else:
                 errprinted = errchk.triggered
                 logger.error(str(exc))
-                event.fire(TaskFailed(task, logfn, localdata, errprinted), localdata)
+                event.fire(TaskFailed(task, fn, logfn, localdata, errprinted), localdata)
             return 1
     finally:
         sys.stdout.flush()
@@ -614,7 +615,7 @@ def _exec_task(fn, task, d, quieterr):
             logger.debug(2, "Zero size logfn %s, removing", logfn)
             bb.utils.remove(logfn)
             bb.utils.remove(loglink)
-    event.fire(TaskSucceeded(task, logfn, localdata), localdata)
+    event.fire(TaskSucceeded(task, fn, logfn, localdata), localdata)
 
     if not localdata.getVarFlag(task, 'nostamp', False) and not localdata.getVarFlag(task, 'selfstamp', False):
         make_stamp(task, localdata)
diff --git a/lib/bb/ui/knotty.py b/lib/bb/ui/knotty.py
index 35736ad..bd9911c 100644
--- a/lib/bb/ui/knotty.py
+++ b/lib/bb/ui/knotty.py
@@ -255,19 +255,19 @@ class TerminalFilter(object):
                 start_time = activetasks[t].get("starttime", None)
                 if not pbar or pbar.bouncing != (progress < 0):
                     if progress < 0:
-                        pbar = BBProgress("0: %s (pid %s) " % (activetasks[t]["title"], t), 100, widgets=[progressbar.BouncingSlider(), ''], extrapos=2, resize_handler=self.sigwinch_handle)
+                        pbar = BBProgress("0: %s (pid %s) " % (activetasks[t]["title"], activetasks[t]["pid"]), 100, widgets=[progressbar.BouncingSlider(), ''], extrapos=2, resize_handler=self.sigwinch_handle)
                         pbar.bouncing = True
                     else:
-                        pbar = BBProgress("0: %s (pid %s) " % (activetasks[t]["title"], t), 100, widgets=[progressbar.Percentage(), ' ', progressbar.Bar(), ''], extrapos=4, resize_handler=self.sigwinch_handle)
+                        pbar = BBProgress("0: %s (pid %s) " % (activetasks[t]["title"], activetasks[t]["pid"]), 100, widgets=[progressbar.Percentage(), ' ', progressbar.Bar(), ''], extrapos=4, resize_handler=self.sigwinch_handle)
                         pbar.bouncing = False
                     activetasks[t]["progressbar"] = pbar
                 tasks.append((pbar, progress, rate, start_time))
             else:
                 start_time = activetasks[t].get("starttime", None)
                 if start_time:
-                    tasks.append("%s - %s (pid %s)" % (activetasks[t]["title"], self.elapsed(currenttime - start_time), t))
+                    tasks.append("%s - %s (pid %s)" % (activetasks[t]["title"], self.elapsed(currenttime - start_time), activetasks[t]["pid"]))
                 else:
-                    tasks.append("%s (pid %s)" % (activetasks[t]["title"], t))
+                    tasks.append("%s (pid %s)" % (activetasks[t]["title"], activetasks[t]["pid"]))
 
         if self.main.shutdown:
             content = "Waiting for %s running tasks to finish:" % len(activetasks)
@@ -517,8 +517,8 @@ def main(server, eventHandler, params, tf = TerminalFilter):
                         continue
 
                     # Prefix task messages with recipe/task
-                    if event.taskpid in helper.running_tasks and event.levelno != format.PLAIN:
-                        taskinfo = helper.running_tasks[event.taskpid]
+                    if event.taskpid in helper.pidmap and event.levelno != format.PLAIN:
+                        taskinfo = helper.running_tasks[helper.pidmap[event.taskpid]]
                         event.msg = taskinfo['title'] + ': ' + event.msg
                 if hasattr(event, 'fn'):
                     event.msg = event.fn + ': ' + event.msg
diff --git a/lib/bb/ui/uihelper.py b/lib/bb/ui/uihelper.py
index c8dd7df..48d808a 100644
--- a/lib/bb/ui/uihelper.py
+++ b/lib/bb/ui/uihelper.py
@@ -15,39 +15,48 @@ class BBUIHelper:
         # Running PIDs preserves the order tasks were executed in
         self.running_pids = []
         self.failed_tasks = []
+        self.pidmap = {}
         self.tasknumber_current = 0
         self.tasknumber_total = 0
 
     def eventHandler(self, event):
+        # PIDs are a bad idea as they can be reused before we process all UI events.
+        # We maintain a 'fuzzy' match for TaskProgress since there is no other way to match
+        def removetid(pid, tid):
+            self.running_pids.remove(tid)
+            del self.running_tasks[tid]
+            if self.pidmap[pid] == tid:
+                del self.pidmap[pid]
+            self.needUpdate = True
+
         if isinstance(event, bb.build.TaskStarted):
+            tid = event._fn + ":" + event._task
             if event._mc != "default":
-                self.running_tasks[event.pid] = { 'title' : "mc:%s:%s %s" % (event._mc, event._package, event._task), 'starttime' : time.time() }
+                self.running_tasks[tid] = { 'title' : "mc:%s:%s %s" % (event._mc, event._package, event._task), 'starttime' : time.time(), 'pid' : event.pid }
             else:
-                self.running_tasks[event.pid] = { 'title' : "%s %s" % (event._package, event._task), 'starttime' : time.time() }
-            self.running_pids.append(event.pid)
+                self.running_tasks[tid] = { 'title' : "%s %s" % (event._package, event._task), 'starttime' : time.time(), 'pid' : event.pid }
+            self.running_pids.append(tid)
+            self.pidmap[event.pid] = tid
             self.needUpdate = True
         elif isinstance(event, bb.build.TaskSucceeded):
-            del self.running_tasks[event.pid]
-            self.running_pids.remove(event.pid)
-            self.needUpdate = True
+            tid = event._fn + ":" + event._task
+            removetid(event.pid, tid)
         elif isinstance(event, bb.build.TaskFailedSilent):
-            del self.running_tasks[event.pid]
-            self.running_pids.remove(event.pid)
+            tid = event._fn + ":" + event._task
+            removetid(event.pid, tid)
             # Don't add to the failed tasks list since this is e.g. a setscene task failure
-            self.needUpdate = True
         elif isinstance(event, bb.build.TaskFailed):
-            del self.running_tasks[event.pid]
-            self.running_pids.remove(event.pid)
+            tid = event._fn + ":" + event._task
+            removetid(event.pid, tid)
             self.failed_tasks.append( { 'title' : "%s %s" % (event._package, event._task)})
-            self.needUpdate = True
         elif isinstance(event, bb.runqueue.runQueueTaskStarted):
             self.tasknumber_current = event.stats.completed + event.stats.active + event.stats.failed + 1
             self.tasknumber_total = event.stats.total
             self.needUpdate = True
         elif isinstance(event, bb.build.TaskProgress):
-            if event.pid > 0:
-                self.running_tasks[event.pid]['progress'] = event.progress
-                self.running_tasks[event.pid]['rate'] = event.rate
+            if event.pid > 0 and event.pid in self.pidmap:
+                self.running_tasks[self.pidmap[event.pid]]['progress'] = event.progress
+                self.running_tasks[self.pidmap[event.pid]]['rate'] = event.rate
                 self.needUpdate = True
         else:
             return False
-- 
2.7.4



^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [1.44 05/18] siggen: Avoid taskhash mismatch errors for nostamp tasks when dependencies rehash
  2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
                   ` (3 preceding siblings ...)
  2019-12-23  4:50 ` [1.44 04/18] knotty/uihelper: Switch from pids to tids for Task event management Armin Kuster
@ 2019-12-23  4:50 ` Armin Kuster
  2019-12-23  4:50 ` [1.44 06/18] siggen: Ensure new unihash propagates through the system Armin Kuster
                   ` (12 subsequent siblings)
  17 siblings, 0 replies; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

From: Richard Purdie <richard.purdie@linuxfoundation.org>

An example:

NOTE: recipe binutils-cross-testsuite-2.32.0-r0: task do_check: Started
ERROR: Taskhash mismatch b074da4334aff8aa06572e7a8725c941fa6b08de4ce714a65a90c0c0b680abea versus 17375278daed609a7129769b74a1336a37bdef14b534ae85189ccc033a9f2db4 for /home/pokybuild/yocto-worker/qemux86-64/build/meta/recipes-devtools/binutils/binutils-cross-testsuite_2.32.bb:do_check
NOTE: recipe binutils-cross-testsuite-2.32.0-r0: task do_check: Succeeded

Is caused by a rehash in a dependency happening somewhere earlier in the build
and the taint being reset.

Change the code so that nostamp taints are preserved to avoid the issue.

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
(cherry picked from commit 61624a3fc38e8546e01356d5ce7a09f21e7094ab)
---
 lib/bb/siggen.py | 12 ++++++++----
 1 file changed, 8 insertions(+), 4 deletions(-)

diff --git a/lib/bb/siggen.py b/lib/bb/siggen.py
index edf1010..de85326 100644
--- a/lib/bb/siggen.py
+++ b/lib/bb/siggen.py
@@ -232,10 +232,14 @@ class SignatureGeneratorBasic(SignatureGenerator):
         taskdep = dataCache.task_deps[fn]
         if 'nostamp' in taskdep and task in taskdep['nostamp']:
             # Nostamp tasks need an implicit taint so that they force any dependent tasks to run
-            import uuid
-            taint = str(uuid.uuid4())
-            data = data + taint
-            self.taints[tid] = "nostamp:" + taint
+            if tid in self.taints and self.taints[tid].startswith("nostamp:"):
+                # Don't reset taint value upon every call
+                data = data + self.taints[tid][8:]
+            else:
+                import uuid
+                taint = str(uuid.uuid4())
+                data = data + taint
+                self.taints[tid] = "nostamp:" + taint
 
         taint = self.read_taint(fn, task, dataCache.stamp[fn])
         if taint:
-- 
2.7.4



^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [1.44 06/18] siggen: Ensure new unihash propagates through the system
  2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
                   ` (4 preceding siblings ...)
  2019-12-23  4:50 ` [1.44 05/18] siggen: Avoid taskhash mismatch errors for nostamp tasks when dependencies rehash Armin Kuster
@ 2019-12-23  4:50 ` Armin Kuster
  2019-12-23  4:50 ` [1.44 07/18] runqueue: Batch scenequeue updates Armin Kuster
                   ` (11 subsequent siblings)
  17 siblings, 0 replies; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

From: Richard Purdie <richard.purdie@linuxfoundation.org>

Its possible the new unihash may not exist in sstate. Currently the code
would create an sstate object with the old hash however this updates it to
create the object with the new unihash.

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
(cherry picked from commit abcaa1398031fa5338a43859c661e6d4a9ce863d)
---
 lib/bb/siggen.py | 1 +
 1 file changed, 1 insertion(+)

diff --git a/lib/bb/siggen.py b/lib/bb/siggen.py
index de85326..dbf5102 100644
--- a/lib/bb/siggen.py
+++ b/lib/bb/siggen.py
@@ -513,6 +513,7 @@ class SignatureGeneratorUniHashMixIn(object):
                     bb.debug(1, 'Task %s unihash changed %s -> %s by server %s' % (taskhash, unihash, new_unihash, self.server))
                     bb.event.fire(bb.runqueue.taskUniHashUpdate(fn + ':do_' + task, new_unihash), d)
                     self.set_unihash(tid, new_unihash)
+                    d.setVar('BB_UNIHASH', new_unihash)
                 else:
                     bb.debug(1, 'Reported task %s as unihash %s to %s' % (taskhash, unihash, self.server))
             except hashserv.client.HashConnectionError as e:
-- 
2.7.4



^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [1.44 07/18] runqueue: Batch scenequeue updates
  2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
                   ` (5 preceding siblings ...)
  2019-12-23  4:50 ` [1.44 06/18] siggen: Ensure new unihash propagates through the system Armin Kuster
@ 2019-12-23  4:50 ` Armin Kuster
  2019-12-23  4:50 ` [1.44 08/18] siggen: Fix performance issue in get_unihash Armin Kuster
                   ` (10 subsequent siblings)
  17 siblings, 0 replies; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

From: Joshua Watt <jpewhacker@gmail.com>

Batch all updates to scenequeue data together in a single invocation
instead of checking each task serially. This allows the checks for
sstate object to happen in parallel, and also makes sure the log
statement only happens once (per set of rehashes).

Signed-off-by: Joshua Watt <JPEWhacker@gmail.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
(cherry picked from commit db033a8f8a276d864bdb2e1eef159ab5794a0658)
---
 lib/bb/runqueue.py | 11 +++++++----
 1 file changed, 7 insertions(+), 4 deletions(-)

diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py
index 246a9cd..cb499a1 100644
--- a/lib/bb/runqueue.py
+++ b/lib/bb/runqueue.py
@@ -2320,6 +2320,7 @@ class RunQueueExecute:
             if tid not in self.pending_migrations:
                 self.pending_migrations.add(tid)
 
+        update_tasks = []
         for tid in self.pending_migrations.copy():
             if tid in self.runq_running or tid in self.sq_live:
                 # Too late, task already running, not much we can do now
@@ -2379,11 +2380,13 @@ class RunQueueExecute:
             if tid in self.build_stamps:
                 del self.build_stamps[tid]
 
-            origvalid = False
-            if tid in self.sqdata.valid:
-                origvalid = True
+            update_tasks.append((tid, harddepfail, tid in self.sqdata.valid))
+
+        if update_tasks:
             self.sqdone = False
-            update_scenequeue_data([tid], self.sqdata, self.rqdata, self.rq, self.cooker, self.stampcache, self, summary=False)
+            update_scenequeue_data([t[0] for t in update_tasks], self.sqdata, self.rqdata, self.rq, self.cooker, self.stampcache, self, summary=False)
+
+        for (tid, harddepfail, origvalid) in update_tasks:
             if tid in self.sqdata.valid and not origvalid:
                 logger.info("Setscene task %s became valid" % tid)
             if harddepfail:
-- 
2.7.4



^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [1.44 08/18] siggen: Fix performance issue in get_unihash
  2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
                   ` (6 preceding siblings ...)
  2019-12-23  4:50 ` [1.44 07/18] runqueue: Batch scenequeue updates Armin Kuster
@ 2019-12-23  4:50 ` Armin Kuster
  2019-12-23  4:50 ` [1.44 09/18] bb.utils.fileslocked: don't leak files if yield throws Armin Kuster
                   ` (9 subsequent siblings)
  17 siblings, 0 replies; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

From: Richard Purdie <richard.purdie@linuxfoundation.org>

There is a significant performance issue in get_unihash(). The issue turns out
to be the lookups of setscene tasks. We can fix this by using a set() instead of
the current list.

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
(cherry picked from commit 1e561672d039ebfb8cd0e0654a44dcf48513317c)
---
 lib/bb/siggen.py | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/lib/bb/siggen.py b/lib/bb/siggen.py
index dbf5102..2fec859 100644
--- a/lib/bb/siggen.py
+++ b/lib/bb/siggen.py
@@ -44,7 +44,7 @@ class SignatureGenerator(object):
         self.file_checksum_values = {}
         self.taints = {}
         self.unitaskhashes = {}
-        self.setscenetasks = {}
+        self.setscenetasks = set()
 
     def finalise(self, fn, d, varient):
         return
@@ -110,7 +110,7 @@ class SignatureGeneratorBasic(SignatureGenerator):
         self.taints = {}
         self.gendeps = {}
         self.lookupcache = {}
-        self.setscenetasks = {}
+        self.setscenetasks = set()
         self.basewhitelist = set((data.getVar("BB_HASHBASE_WHITELIST") or "").split())
         self.taskwhitelist = None
         self.init_rundepcheck(data)
@@ -157,7 +157,7 @@ class SignatureGeneratorBasic(SignatureGenerator):
         return taskdeps
 
     def set_setscene_tasks(self, setscene_tasks):
-        self.setscenetasks = setscene_tasks
+        self.setscenetasks = set(setscene_tasks)
 
     def finalise(self, fn, d, variant):
 
-- 
2.7.4



^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [1.44 09/18] bb.utils.fileslocked: don't leak files if yield throws
  2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
                   ` (7 preceding siblings ...)
  2019-12-23  4:50 ` [1.44 08/18] siggen: Fix performance issue in get_unihash Armin Kuster
@ 2019-12-23  4:50 ` Armin Kuster
  2019-12-23  4:50 ` [1.44 10/18] runqueue: Rework process_possible_migrations() to improve performance Armin Kuster
                   ` (8 subsequent siblings)
  17 siblings, 0 replies; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

From: Chris Laplante via bitbake-devel <bitbake-devel@lists.openembedded.org>

Discovered with a recipe under devtool. The ${S}/singletask.lock file (added by
externalsrc.bbclass) was leaked, giving a warning like:

  WARNING: <PN>+git999-r0 do_populate_lic: /home/laplante/yocto/sources/poky/bitbake/lib/bb/build.py:582: ResourceWarning: unclosed file <_io.TextIOWrapper name='/home/laplante/yocto/build/workspace/sources/<PN>/singletask.lock' mode='a+' encoding='UTF-8'>
    exec_func(task, localdata)

Signed-off-by: Chris Laplante <chris.laplante@agilent.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
(cherry picked from commit 6beddf6214e22b4002626761031a9e9d34fb04db)
---
 lib/bb/utils.py | 9 +++++----
 1 file changed, 5 insertions(+), 4 deletions(-)

diff --git a/lib/bb/utils.py b/lib/bb/utils.py
index 8d40bcd..d65265c 100644
--- a/lib/bb/utils.py
+++ b/lib/bb/utils.py
@@ -428,10 +428,11 @@ def fileslocked(files):
         for lockfile in files:
             locks.append(bb.utils.lockfile(lockfile))
 
-    yield
-
-    for lock in locks:
-        bb.utils.unlockfile(lock)
+    try:
+        yield
+    finally:
+        for lock in locks:
+            bb.utils.unlockfile(lock)
 
 @contextmanager
 def timeout(seconds):
-- 
2.7.4



^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [1.44 10/18] runqueue: Rework process_possible_migrations() to improve performance
  2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
                   ` (8 preceding siblings ...)
  2019-12-23  4:50 ` [1.44 09/18] bb.utils.fileslocked: don't leak files if yield throws Armin Kuster
@ 2019-12-23  4:50 ` Armin Kuster
  2019-12-23  4:50 ` [1.44 11/18] runqueue: Fix task mismatch failures from incorrect logic Armin Kuster
                   ` (7 subsequent siblings)
  17 siblings, 0 replies; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

From: Richard Purdie <richard.purdie@linuxfoundation.org>

The looping over multiple changed hashes causes many calls to get_taskhash
and get_unihash which are potentially slow and then overwritten.

Instead, batch up all the tasks which have changed unihashes and then
do one big loop over the changed tasks rather than each in turn.

This makes worlds of difference to the performance graphs and should speed
up build where many tasks are being rehashed.

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
(cherry picked from commit c9c68d898985cf0bec6fc95f54c151cc50255cac)
---
 lib/bb/runqueue.py | 103 +++++++++++++++++++++++++++++------------------------
 1 file changed, 56 insertions(+), 47 deletions(-)

diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py
index cb499a1..a45b27c 100644
--- a/lib/bb/runqueue.py
+++ b/lib/bb/runqueue.py
@@ -2248,6 +2248,7 @@ class RunQueueExecute:
     def process_possible_migrations(self):
 
         changed = set()
+        toprocess = set()
         for tid, unihash in self.updated_taskhash_queue.copy():
             if tid in self.runq_running and tid not in self.runq_complete:
                 continue
@@ -2258,53 +2259,61 @@ class RunQueueExecute:
                 logger.info("Task %s unihash changed to %s" % (tid, unihash))
                 self.rqdata.runtaskentries[tid].unihash = unihash
                 bb.parse.siggen.set_unihash(tid, unihash)
-
-                # Work out all tasks which depend on this one
-                total = set()
-                next = set(self.rqdata.runtaskentries[tid].revdeps)
-                while next:
-                    current = next.copy()
-                    total = total |next
-                    next = set()
-                    for ntid in current:
-                        next |= self.rqdata.runtaskentries[ntid].revdeps
-                        next.difference_update(total)
-
-                # Now iterate those tasks in dependency order to regenerate their taskhash/unihash
-                done = set()
-                next = set(self.rqdata.runtaskentries[tid].revdeps)
-                while next:
-                    current = next.copy()
-                    next = set()
-                    for tid in current:
-                        if not self.rqdata.runtaskentries[tid].depends.isdisjoint(total):
-                            continue
-                        procdep = []
-                        for dep in self.rqdata.runtaskentries[tid].depends:
-                            procdep.append(dep)
-                        orighash = self.rqdata.runtaskentries[tid].hash
-                        newhash = bb.parse.siggen.get_taskhash(tid, procdep, self.rqdata.dataCaches[mc_from_tid(tid)])
-                        origuni = self.rqdata.runtaskentries[tid].unihash
-                        newuni = bb.parse.siggen.get_unihash(tid)
-                        # FIXME, need to check it can come from sstate at all for determinism?
-                        remapped = False
-                        if newuni == origuni:
-                            # Nothing to do, we match, skip code below
-                            remapped = True
-                        elif tid in self.scenequeue_covered or tid in self.sq_live:
-                            # Already ran this setscene task or it running. Report the new taskhash
-                            remapped = bb.parse.siggen.report_unihash_equiv(tid, newhash, origuni, newuni, self.rqdata.dataCaches)
-                            logger.info("Already covered setscene for %s so ignoring rehash (remap)" % (tid))
-
-                        if not remapped:
-                            logger.debug(1, "Task %s hash changes: %s->%s %s->%s" % (tid, orighash, newhash, origuni, newuni))
-                            self.rqdata.runtaskentries[tid].hash = newhash
-                            self.rqdata.runtaskentries[tid].unihash = newuni
-                            changed.add(tid)
-
-                        next |= self.rqdata.runtaskentries[tid].revdeps
-                        total.remove(tid)
-                        next.intersection_update(total)
+                toprocess.add(tid)
+
+        # Work out all tasks which depend upon these
+        total = set()
+        for p in toprocess:
+            next = set(self.rqdata.runtaskentries[p].revdeps)
+            while next:
+                current = next.copy()
+                total = total | next
+                next = set()
+                for ntid in current:
+                    next |= self.rqdata.runtaskentries[ntid].revdeps
+                    next.difference_update(total)
+
+        # Now iterate those tasks in dependency order to regenerate their taskhash/unihash
+        next = set()
+        for p in total:
+            if len(self.rqdata.runtaskentries[p].depends) == 0:
+                next.add(p)
+            elif self.rqdata.runtaskentries[p].depends.isdisjoint(total):
+                next.add(p)
+
+        # When an item doesn't have dependencies in total, we can process it. Drop items from total when handled
+        while next:
+            current = next.copy()
+            next = set()
+            for tid in current:
+                if not self.rqdata.runtaskentries[tid].depends.isdisjoint(total):
+                    continue
+                procdep = []
+                for dep in self.rqdata.runtaskentries[tid].depends:
+                    procdep.append(dep)
+                orighash = self.rqdata.runtaskentries[tid].hash
+                newhash = bb.parse.siggen.get_taskhash(tid, procdep, self.rqdata.dataCaches[mc_from_tid(tid)])
+                origuni = self.rqdata.runtaskentries[tid].unihash
+                newuni = bb.parse.siggen.get_unihash(tid)
+                # FIXME, need to check it can come from sstate at all for determinism?
+                remapped = False
+                if newuni == origuni:
+                    # Nothing to do, we match, skip code below
+                    remapped = True
+                elif tid in self.scenequeue_covered or tid in self.sq_live:
+                    # Already ran this setscene task or it running. Report the new taskhash
+                    remapped = bb.parse.siggen.report_unihash_equiv(tid, newhash, origuni, newuni, self.rqdata.dataCaches)
+                    logger.info("Already covered setscene for %s so ignoring rehash (remap)" % (tid))
+
+                if not remapped:
+                    #logger.debug(1, "Task %s hash changes: %s->%s %s->%s" % (tid, orighash, newhash, origuni, newuni))
+                    self.rqdata.runtaskentries[tid].hash = newhash
+                    self.rqdata.runtaskentries[tid].unihash = newuni
+                    changed.add(tid)
+
+                next |= self.rqdata.runtaskentries[tid].revdeps
+                total.remove(tid)
+                next.intersection_update(total)
 
         if changed:
             for mc in self.rq.worker:
-- 
2.7.4



^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [1.44 11/18] runqueue: Fix task mismatch failures from incorrect logic
  2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
                   ` (9 preceding siblings ...)
  2019-12-23  4:50 ` [1.44 10/18] runqueue: Rework process_possible_migrations() to improve performance Armin Kuster
@ 2019-12-23  4:50 ` Armin Kuster
  2019-12-23  4:50 ` [1.44 12/18] siggen: Split get_tashhash for performance Armin Kuster
                   ` (6 subsequent siblings)
  17 siblings, 0 replies; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

From: Richard Purdie <richard.purdie@linuxfoundation.org>

The "no dependencies" task case was not being correctly considered in this
code and seemed to be the cause of occasionaly task hash mismatch errors
that were being seen as the dependencies were never accounted for properly.

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
(cherry picked from commit 608b9f821539de813bfbd9e65950dbc56a274bc2)
---
 lib/bb/runqueue.py | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py
index a45b27c..b3648dd 100644
--- a/lib/bb/runqueue.py
+++ b/lib/bb/runqueue.py
@@ -2286,7 +2286,7 @@ class RunQueueExecute:
             current = next.copy()
             next = set()
             for tid in current:
-                if not self.rqdata.runtaskentries[tid].depends.isdisjoint(total):
+                if len(self.rqdata.runtaskentries[p].depends) and not self.rqdata.runtaskentries[tid].depends.isdisjoint(total):
                     continue
                 procdep = []
                 for dep in self.rqdata.runtaskentries[tid].depends:
-- 
2.7.4



^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [1.44 12/18] siggen: Split get_tashhash for performance
  2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
                   ` (10 preceding siblings ...)
  2019-12-23  4:50 ` [1.44 11/18] runqueue: Fix task mismatch failures from incorrect logic Armin Kuster
@ 2019-12-23  4:50 ` Armin Kuster
  2019-12-23  4:50 ` [1.44 13/18] runqueue: Fix sstate task iteration performance Armin Kuster
                   ` (5 subsequent siblings)
  17 siblings, 0 replies; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

From: Richard Purdie <richard.purdie@linuxfoundation.org>

There are two operations happening in get_taskhash, the building of the
underlying data and the calculation of the hash.

Split these into two funtions since the preparation part doesn't need
to rerun when unihash changes, only the calculation does.

This split allows sigificant performance improvements for hashequiv
in builds where many hashes are equivalent and many hashes are changing.

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
(cherry picked from commit 6a32af2808d748819f4af55c443578c8a63062b3)
---
 lib/bb/runqueue.py |  1 +
 lib/bb/siggen.py   | 33 ++++++++++++++++++++++++---------
 2 files changed, 25 insertions(+), 9 deletions(-)

diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py
index b3648dd..515e9d4 100644
--- a/lib/bb/runqueue.py
+++ b/lib/bb/runqueue.py
@@ -1185,6 +1185,7 @@ class RunQueueData:
         procdep = []
         for dep in self.runtaskentries[tid].depends:
             procdep.append(dep)
+        bb.parse.siggen.prep_taskhash(tid, procdep, self.dataCaches[mc_from_tid(tid)])
         self.runtaskentries[tid].hash = bb.parse.siggen.get_taskhash(tid, procdep, self.dataCaches[mc_from_tid(tid)])
         self.runtaskentries[tid].unihash = bb.parse.siggen.get_unihash(tid)
 
diff --git a/lib/bb/siggen.py b/lib/bb/siggen.py
index 2fec859..e484e5e 100644
--- a/lib/bb/siggen.py
+++ b/lib/bb/siggen.py
@@ -52,6 +52,9 @@ class SignatureGenerator(object):
     def get_unihash(self, tid):
         return self.taskhash[tid]
 
+    def prep_taskhash(self, tid, deps, dataCache):
+        return
+
     def get_taskhash(self, tid, deps, dataCache):
         self.taskhash[tid] = hashlib.sha256(tid.encode("utf-8")).hexdigest()
         return self.taskhash[tid]
@@ -198,12 +201,11 @@ class SignatureGeneratorBasic(SignatureGenerator):
             pass
         return taint
 
-    def get_taskhash(self, tid, deps, dataCache):
+    def prep_taskhash(self, tid, deps, dataCache):
 
         (mc, _, task, fn) = bb.runqueue.split_tid_mcfn(tid)
 
-        data = dataCache.basetaskhash[tid]
-        self.basehash[tid] = data
+        self.basehash[tid] = dataCache.basetaskhash[tid]
         self.runtaskdeps[tid] = []
         self.file_checksum_values[tid] = []
         recipename = dataCache.pkg_fn[fn]
@@ -216,7 +218,6 @@ class SignatureGeneratorBasic(SignatureGenerator):
                 continue
             if dep not in self.taskhash:
                 bb.fatal("%s is not in taskhash, caller isn't calling in dependency order?" % dep)
-            data = data + self.get_unihash(dep)
             self.runtaskdeps[tid].append(dep)
 
         if task in dataCache.file_checksums[fn]:
@@ -226,27 +227,41 @@ class SignatureGeneratorBasic(SignatureGenerator):
                 checksums = bb.fetch2.get_file_checksums(dataCache.file_checksums[fn][task], recipename)
             for (f,cs) in checksums:
                 self.file_checksum_values[tid].append((f,cs))
-                if cs:
-                    data = data + cs
 
         taskdep = dataCache.task_deps[fn]
         if 'nostamp' in taskdep and task in taskdep['nostamp']:
             # Nostamp tasks need an implicit taint so that they force any dependent tasks to run
             if tid in self.taints and self.taints[tid].startswith("nostamp:"):
                 # Don't reset taint value upon every call
-                data = data + self.taints[tid][8:]
+                pass
             else:
                 import uuid
                 taint = str(uuid.uuid4())
-                data = data + taint
                 self.taints[tid] = "nostamp:" + taint
 
         taint = self.read_taint(fn, task, dataCache.stamp[fn])
         if taint:
-            data = data + taint
             self.taints[tid] = taint
             logger.warning("%s is tainted from a forced run" % tid)
 
+        return
+
+    def get_taskhash(self, tid, deps, dataCache):
+
+        data = self.basehash[tid]
+        for dep in self.runtaskdeps[tid]:
+            data = data + self.get_unihash(dep)
+
+        for (f, cs) in self.file_checksum_values[tid]:
+            if cs:
+                data = data + cs
+
+        if tid in self.taints:
+            if self.taints[tid].startswith("nostamp:"):
+                data = data + self.taints[tid][8:]
+            else:
+                data = data + self.taints[tid]
+
         h = hashlib.sha256(data.encode("utf-8")).hexdigest()
         self.taskhash[tid] = h
         #d.setVar("BB_TASKHASH_task-%s" % task, taskhash[task])
-- 
2.7.4



^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [1.44 13/18] runqueue: Fix sstate task iteration performance
  2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
                   ` (11 preceding siblings ...)
  2019-12-23  4:50 ` [1.44 12/18] siggen: Split get_tashhash for performance Armin Kuster
@ 2019-12-23  4:50 ` Armin Kuster
  2019-12-23  4:50 ` [1.44 14/18] runqueue: Optimise task migration code slightly Armin Kuster
                   ` (4 subsequent siblings)
  17 siblings, 0 replies; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

From: Richard Purdie <richard.purdie@linuxfoundation.org>

Creating a new sorted list of sstate tasks each iteration through runqueue is
extremely ineffecient and was compounded by the recent change from a list to set.

Create one sorted list instead of recreating it each time.

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
(cherry picked from commit de18824996841c3f35f54ff5ad12f94f6dc20d88)
---
 lib/bb/runqueue.py | 6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)

diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py
index 515e9d4..2ba4557 100644
--- a/lib/bb/runqueue.py
+++ b/lib/bb/runqueue.py
@@ -1965,10 +1965,14 @@ class RunQueueExecute:
         self.rq.read_workers()
         self.process_possible_migrations()
 
+        if not hasattr(self, "sorted_setscene_tids"):
+            # Don't want to sort this set every execution
+            self.sorted_setscene_tids = sorted(self.rqdata.runq_setscene_tids)
+
         task = None
         if not self.sqdone and self.can_start_task():
             # Find the next setscene to run
-            for nexttask in sorted(self.rqdata.runq_setscene_tids):
+            for nexttask in self.sorted_setscene_tids:
                 if nexttask in self.sq_buildable and nexttask not in self.sq_running and self.sqdata.stamps[nexttask] not in self.build_stamps.values():
                     if nexttask not in self.sqdata.unskippable and len(self.sqdata.sq_revdeps[nexttask]) > 0 and self.sqdata.sq_revdeps[nexttask].issubset(self.scenequeue_covered) and self.check_dependencies(nexttask, self.sqdata.sq_revdeps[nexttask]):
                         if nexttask not in self.rqdata.target_tids:
-- 
2.7.4



^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [1.44 14/18] runqueue: Optimise task migration code slightly
  2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
                   ` (12 preceding siblings ...)
  2019-12-23  4:50 ` [1.44 13/18] runqueue: Fix sstate task iteration performance Armin Kuster
@ 2019-12-23  4:50 ` Armin Kuster
  2019-12-23  4:50 ` [1.44 15/18] runqueue: Optimise out pointless loop iteration Armin Kuster
                   ` (3 subsequent siblings)
  17 siblings, 0 replies; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

From: Richard Purdie <richard.purdie@linuxfoundation.org>

Move the calls to difference_update out a code level which improves efficiency
significantly.

Also further combine the outer loop for efficiency too.

These two changes remove a bottleneck from the performance charts.

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
(cherry picked from commit e28ec69356f1797de3e4e3fca0fef710bc4564de)
---
 lib/bb/runqueue.py | 17 +++++++++--------
 1 file changed, 9 insertions(+), 8 deletions(-)

diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py
index 2ba4557..6da612b 100644
--- a/lib/bb/runqueue.py
+++ b/lib/bb/runqueue.py
@@ -2268,15 +2268,16 @@ class RunQueueExecute:
 
         # Work out all tasks which depend upon these
         total = set()
+        next = set()
         for p in toprocess:
-            next = set(self.rqdata.runtaskentries[p].revdeps)
-            while next:
-                current = next.copy()
-                total = total | next
-                next = set()
-                for ntid in current:
-                    next |= self.rqdata.runtaskentries[ntid].revdeps
-                    next.difference_update(total)
+            next |= self.rqdata.runtaskentries[p].revdeps
+        while next:
+            current = next.copy()
+            total = total | next
+            next = set()
+            for ntid in current:
+                next |= self.rqdata.runtaskentries[ntid].revdeps
+            next.difference_update(total)
 
         # Now iterate those tasks in dependency order to regenerate their taskhash/unihash
         next = set()
-- 
2.7.4



^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [1.44 15/18] runqueue: Optimise out pointless loop iteration
  2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
                   ` (13 preceding siblings ...)
  2019-12-23  4:50 ` [1.44 14/18] runqueue: Optimise task migration code slightly Armin Kuster
@ 2019-12-23  4:50 ` Armin Kuster
  2019-12-23  4:50 ` [1.44 16/18] runqueue: Optimise task filtering Armin Kuster
                   ` (2 subsequent siblings)
  17 siblings, 0 replies; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

From: Richard Purdie <richard.purdie@linuxfoundation.org>

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
(cherry picked from commit 105d1f0748edde7753a4063e6fdc758ffc8a8a9e)
---
 lib/bb/runqueue.py | 12 +++---------
 1 file changed, 3 insertions(+), 9 deletions(-)

diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py
index 6da612b..73775d9 100644
--- a/lib/bb/runqueue.py
+++ b/lib/bb/runqueue.py
@@ -1182,11 +1182,8 @@ class RunQueueData:
         return len(self.runtaskentries)
 
     def prepare_task_hash(self, tid):
-        procdep = []
-        for dep in self.runtaskentries[tid].depends:
-            procdep.append(dep)
-        bb.parse.siggen.prep_taskhash(tid, procdep, self.dataCaches[mc_from_tid(tid)])
-        self.runtaskentries[tid].hash = bb.parse.siggen.get_taskhash(tid, procdep, self.dataCaches[mc_from_tid(tid)])
+        bb.parse.siggen.prep_taskhash(tid, self.runtaskentries[tid].depends, self.dataCaches[mc_from_tid(tid)])
+        self.runtaskentries[tid].hash = bb.parse.siggen.get_taskhash(tid, self.runtaskentries[tid].depends, self.dataCaches[mc_from_tid(tid)])
         self.runtaskentries[tid].unihash = bb.parse.siggen.get_unihash(tid)
 
     def dump_data(self):
@@ -2294,11 +2291,8 @@ class RunQueueExecute:
             for tid in current:
                 if len(self.rqdata.runtaskentries[p].depends) and not self.rqdata.runtaskentries[tid].depends.isdisjoint(total):
                     continue
-                procdep = []
-                for dep in self.rqdata.runtaskentries[tid].depends:
-                    procdep.append(dep)
                 orighash = self.rqdata.runtaskentries[tid].hash
-                newhash = bb.parse.siggen.get_taskhash(tid, procdep, self.rqdata.dataCaches[mc_from_tid(tid)])
+                newhash = bb.parse.siggen.get_taskhash(tid, self.rqdata.runtaskentries[tid].depends, self.rqdata.dataCaches[mc_from_tid(tid)])
                 origuni = self.rqdata.runtaskentries[tid].unihash
                 newuni = bb.parse.siggen.get_unihash(tid)
                 # FIXME, need to check it can come from sstate at all for determinism?
-- 
2.7.4



^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [1.44 16/18] runqueue: Optimise task filtering
  2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
                   ` (14 preceding siblings ...)
  2019-12-23  4:50 ` [1.44 15/18] runqueue: Optimise out pointless loop iteration Armin Kuster
@ 2019-12-23  4:50 ` Armin Kuster
  2019-12-23  4:50 ` [1.44 17/18] runqueue: Only call into the migrations function if migrations active Armin Kuster
  2019-12-23  4:50 ` [1.44 18/18] lib/bb: Optimise out debug messages from cooker Armin Kuster
  17 siblings, 0 replies; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

From: Richard Purdie <richard.purdie@linuxfoundation.org>

We were seeing this running thousands of times with hashequiv, do
the filtering where it makes more sense and make it persist.

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
(cherry picked from commit 2cfeb9998a8ad5b1dcda0bb4e192c5e4306dab17)
---
 lib/bb/runqueue.py | 5 ++---
 1 file changed, 2 insertions(+), 3 deletions(-)

diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py
index 73775d9..b90ac87 100644
--- a/lib/bb/runqueue.py
+++ b/lib/bb/runqueue.py
@@ -148,8 +148,9 @@ class RunQueueScheduler(object):
         """
         Return the id of the first task we find that is buildable
         """
+        # Once tasks are running we don't need to worry about them again
+        self.buildable.difference_update(self.rq.runq_running)
         buildable = set(self.buildable)
-        buildable.difference_update(self.rq.runq_running)
         buildable.difference_update(self.rq.holdoff_tasks)
         buildable.intersection_update(self.rq.tasks_covered | self.rq.tasks_notcovered)
         if not buildable:
@@ -207,8 +208,6 @@ class RunQueueScheduler(object):
 
     def newbuildable(self, task):
         self.buildable.add(task)
-        # Once tasks are running we don't need to worry about them again
-        self.buildable.difference_update(self.rq.runq_running)
 
     def removebuildable(self, task):
         self.buildable.remove(task)
-- 
2.7.4



^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [1.44 17/18] runqueue: Only call into the migrations function if migrations active
  2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
                   ` (15 preceding siblings ...)
  2019-12-23  4:50 ` [1.44 16/18] runqueue: Optimise task filtering Armin Kuster
@ 2019-12-23  4:50 ` Armin Kuster
  2019-12-23  4:50 ` [1.44 18/18] lib/bb: Optimise out debug messages from cooker Armin Kuster
  17 siblings, 0 replies; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

From: Richard Purdie <richard.purdie@linuxfoundation.org>

This doesn't save much time but does make the profile counts for the
function more accurate which is in itself useful.

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
(cherry picked from commit d446fa89d206fbc6d098215163c968ea5a8cf4a9)
---
 lib/bb/runqueue.py | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py
index b90ac87..729439e 100644
--- a/lib/bb/runqueue.py
+++ b/lib/bb/runqueue.py
@@ -1959,7 +1959,8 @@ class RunQueueExecute:
         """
 
         self.rq.read_workers()
-        self.process_possible_migrations()
+        if self.updated_taskhash_queue or self.pending_migrations:
+            self.process_possible_migrations()
 
         if not hasattr(self, "sorted_setscene_tids"):
             # Don't want to sort this set every execution
-- 
2.7.4



^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [1.44 18/18] lib/bb: Optimise out debug messages from cooker
  2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
                   ` (16 preceding siblings ...)
  2019-12-23  4:50 ` [1.44 17/18] runqueue: Only call into the migrations function if migrations active Armin Kuster
@ 2019-12-23  4:50 ` Armin Kuster
  17 siblings, 0 replies; 22+ messages in thread
From: Armin Kuster @ 2019-12-23  4:50 UTC (permalink / raw)
  To: bitbake-devel

From: Richard Purdie <richard.purdie@linuxfoundation.org>

We have bb.debug(2, xxx) messages in cooker which are useful for debugging
but have really bad effects on performance, 640,000 calls on recent profile
graphs taking tens of seconds.

Rather than commenting out debug which can be useful for debugging, don't
create events for debug log messages from cooker which would never be seen.
We already stop the messages hitting the IPC but this avoids the overhead
of creating the log messages too, which has been shown to be signficiant
on the profiles. This allows the code to perform whilst allowing debug
messages to be availble when wanted/enabled.

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
(cherry picked from commit f04cd931091fb0508badf3e002d70a6952700495)
---
 lib/bb/__init__.py | 5 +++++
 1 file changed, 5 insertions(+)

diff --git a/lib/bb/__init__.py b/lib/bb/__init__.py
index c144311..ce519ba 100644
--- a/lib/bb/__init__.py
+++ b/lib/bb/__init__.py
@@ -43,6 +43,11 @@ class BBLogger(Logger):
         Logger.__init__(self, name)
 
     def bbdebug(self, level, msg, *args, **kwargs):
+        if not bb.event.worker_pid:
+            if self.name in bb.msg.loggerDefaultDomains and level > (bb.msg.loggerDefaultDomains[self.name]):
+                return
+            if level > (bb.msg.loggerDefaultDebugLevel):
+                return
         return self.log(logging.DEBUG - level + 1, msg, *args, **kwargs)
 
     def plain(self, msg, *args, **kwargs):
-- 
2.7.4



^ permalink raw reply related	[flat|nested] 22+ messages in thread

* Re: [1.44 02/18] runqueue/siggen: Allow handling of equivalent hashes
  2019-12-23  4:50 ` [1.44 02/18] runqueue/siggen: Allow handling of equivalent hashes Armin Kuster
@ 2019-12-23  8:25   ` Peter Kjellerstedt
  2019-12-23 16:18     ` akuster808
  2019-12-28 12:24     ` Richard Purdie
  0 siblings, 2 replies; 22+ messages in thread
From: Peter Kjellerstedt @ 2019-12-23  8:25 UTC (permalink / raw)
  To: Armin Kuster, bitbake-devel

> -----Original Message-----
> From: bitbake-devel-bounces@lists.openembedded.org <bitbake-devel-
> bounces@lists.openembedded.org> On Behalf Of Armin Kuster
> Sent: den 23 december 2019 05:50
> To: bitbake-devel@lists.openembedded.org
> Subject: [bitbake-devel] [1.44 02/18] runqueue/siggen: Allow handling of
> equivalent hashes
> 
> From: Richard Purdie <richard.purdie@linuxfoundation.org>
> 
> Based on the hashserv's new ability to accept hash mappings, update
> runqueue
> to use this through a helper function in siggen.
> 
> This addresses problems with meta-extsdk-toolchain and its dependency on
> gdb-cross which caused errors when building eSDK. See the previous commit
> for more details.
> 
> Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
> (cherry picked from commit 39098b4ba2133f4d9229a0aa4fcf4c3e1291286a)
> ---
>  lib/bb/runqueue.py | 31 +++++++++++++++++++------------
>  lib/bb/siggen.py   | 26 ++++++++++++++++++++++++++
>  2 files changed, 45 insertions(+), 12 deletions(-)
> 
> diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py
> index bd7f03f..a869ba5 100644
> --- a/lib/bb/runqueue.py
> +++ b/lib/bb/runqueue.py
> @@ -2283,12 +2283,26 @@ class RunQueueExecute:
>                          for dep in self.rqdata.runtaskentries[tid].depends:
>                              procdep.append(dep)
>                          orighash = self.rqdata.runtaskentries[tid].hash
> -                        self.rqdata.runtaskentries[tid].hash = bb.parse.siggen.get_taskhash(tid, procdep, self.rqdata.dataCaches[mc_from_tid(tid)])
> +                        newhash = bb.parse.siggen.get_taskhash(tid, procdep, self.rqdata.dataCaches[mc_from_tid(tid)])
>                          origuni = self.rqdata.runtaskentries[tid].unihash
> -                        self.rqdata.runtaskentries[tid].unihash = bb.parse.siggen.get_unihash(tid)
> -                        logger.debug(1, "Task %s hash changes: %s->%s %s->%s" % (tid, orighash, self.rqdata.runtaskentries[tid].hash, origuni, self.rqdata.runtaskentries[tid].unihash))
> +                        newuni = bb.parse.siggen.get_unihash(tid)
> +                        # FIXME, need to check it can come from sstate at all for determinism?
> +                        remapped = False
> +                        if newuni == origuni:
> +                            # Nothing to do, we match, skip code below
> +                            remapped = True
> +                        elif tid in self.scenequeue_covered or tid in self.sq_live:
> +                            # Already ran this setscene task or it running. Report the new taskhash
> +                            remapped = bb.parse.siggen.report_unihash_equiv(tid, newhash, origuni, newuni, self.rqdata.dataCaches)
> +                            logger.info("Already covered setscene for %s so ignoring rehash (remap)" % (tid))

Do we really want this level of logging? I have not commented on it for 
master (yet), as I expect it is invaluable for RP & co that are currently 
working hard on the hash server, but for me as common user of bitbake, 
this is just noise (and a lot of it). I have a local patch that changes 
this to logger.debug(1, ...) together with another logger.info("Task %s 
unihash changed to %s" ...) a few lines earlier to get the cooker UI 
reasonably back to usable. Also see below.

> +
> +                        if not remapped:
> +                            logger.debug(1, "Task %s hash changes: %s->%s %s->%s" % (tid, orighash, newhash, origuni, newuni))
> +                            self.rqdata.runtaskentries[tid].hash = newhash
> +                            self.rqdata.runtaskentries[tid].unihash = newuni
> +                            changed.add(tid)
> +
>                          next |= self.rqdata.runtaskentries[tid].revdeps
> -                        changed.add(tid)
>                          total.remove(tid)
>                          next.intersection_update(total)
> 
> @@ -2307,18 +2321,11 @@ class RunQueueExecute:
>                  self.pending_migrations.add(tid)
> 
>          for tid in self.pending_migrations.copy():
> -            if tid in self.runq_running:
> +            if tid in self.runq_running or tid in self.sq_live:
>                  # Too late, task already running, not much we can do now
>                  self.pending_migrations.remove(tid)
>                  continue
> 
> -            if tid in self.scenequeue_covered or tid in self.sq_live:
> -                # Already ran this setscene task or it running
> -                # Potentially risky, should we report this hash as a match?
> -                logger.info("Already covered setscene for %s so ignoring rehash" % (tid))
> -                self.pending_migrations.remove(tid)
> -                continue
> -
>              valid = True
>              # Check no tasks this covers are running
>              for dep in self.sqdata.sq_covered_tasks[tid]:
> diff --git a/lib/bb/siggen.py b/lib/bb/siggen.py
> index e19812b..edf1010 100644
> --- a/lib/bb/siggen.py
> +++ b/lib/bb/siggen.py
> @@ -525,6 +525,32 @@ class SignatureGeneratorUniHashMixIn(object):
>                  except OSError:
>                      pass
> 
> +    def report_unihash_equiv(self, tid, taskhash, wanted_unihash, current_unihash, datacaches):
> +        try:
> +            extra_data = {}
> +            data = self.client().report_unihash_equiv(taskhash, self.method, wanted_unihash, extra_data)
> +            bb.note('Reported task %s as unihash %s to %s (%s)' % (tid, wanted_unihash, self.server, str(data)))

This one and ...

> +
> +            if data is None:
> +                bb.warn("Server unable to handle unihash report")
> +                return False
> +
> +            finalunihash = data['unihash']
> +
> +            if finalunihash == current_unihash:
> +                bb.note('Task %s unihash %s unchanged by server' % (tid, finalunihash))
> +            elif finalunihash == wanted_unihash:
> +                bb.note('Task %s unihash changed %s -> %s as wanted' % (tid, current_unihash, finalunihash))
> +                self.set_unihash(tid, finalunihash)
> +                return True
> +            else:
> +                # TODO: What to do here?
> +                bb.note('Task %s unihash reported as unwanted hash %s' % (tid, finalunihash))

... and these also seem excessive. I have changed them locally to 
bb.debug(1, ...) too.

> +        except hashserv.client.HashConnectionError as e:
> +            bb.warn('Error contacting Hash Equivalence Server %s: %s' % (self.server, str(e)))
> +
> +        return False
> 
>  #
>  # Dummy class used for bitbake-selftest
> --
> 2.7.4

//Peter



^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [1.44 02/18] runqueue/siggen: Allow handling of equivalent hashes
  2019-12-23  8:25   ` Peter Kjellerstedt
@ 2019-12-23 16:18     ` akuster808
  2019-12-28 12:24     ` Richard Purdie
  1 sibling, 0 replies; 22+ messages in thread
From: akuster808 @ 2019-12-23 16:18 UTC (permalink / raw)
  To: Peter Kjellerstedt, bitbake-devel



On 12/23/19 12:25 AM, Peter Kjellerstedt wrote:
>> -----Original Message-----
>> From: bitbake-devel-bounces@lists.openembedded.org <bitbake-devel-
>> bounces@lists.openembedded.org> On Behalf Of Armin Kuster
>> Sent: den 23 december 2019 05:50
>> To: bitbake-devel@lists.openembedded.org
>> Subject: [bitbake-devel] [1.44 02/18] runqueue/siggen: Allow handling of
>> equivalent hashes
>>
>> From: Richard Purdie <richard.purdie@linuxfoundation.org>
>>
>> Based on the hashserv's new ability to accept hash mappings, update
>> runqueue
>> to use this through a helper function in siggen.
>>
>> This addresses problems with meta-extsdk-toolchain and its dependency on
>> gdb-cross which caused errors when building eSDK. See the previous commit
>> for more details.
>>
>> Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
>> (cherry picked from commit 39098b4ba2133f4d9229a0aa4fcf4c3e1291286a)
>> ---
>>  lib/bb/runqueue.py | 31 +++++++++++++++++++------------
>>  lib/bb/siggen.py   | 26 ++++++++++++++++++++++++++
>>  2 files changed, 45 insertions(+), 12 deletions(-)
>>
>> diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py
>> index bd7f03f..a869ba5 100644
>> --- a/lib/bb/runqueue.py
>> +++ b/lib/bb/runqueue.py
>> @@ -2283,12 +2283,26 @@ class RunQueueExecute:
>>                          for dep in self.rqdata.runtaskentries[tid].depends:
>>                              procdep.append(dep)
>>                          orighash = self.rqdata.runtaskentries[tid].hash
>> -                        self.rqdata.runtaskentries[tid].hash = bb.parse.siggen.get_taskhash(tid, procdep, self.rqdata.dataCaches[mc_from_tid(tid)])
>> +                        newhash = bb.parse.siggen.get_taskhash(tid, procdep, self.rqdata.dataCaches[mc_from_tid(tid)])
>>                          origuni = self.rqdata.runtaskentries[tid].unihash
>> -                        self.rqdata.runtaskentries[tid].unihash = bb.parse.siggen.get_unihash(tid)
>> -                        logger.debug(1, "Task %s hash changes: %s->%s %s->%s" % (tid, orighash, self.rqdata.runtaskentries[tid].hash, origuni, self.rqdata.runtaskentries[tid].unihash))
>> +                        newuni = bb.parse.siggen.get_unihash(tid)
>> +                        # FIXME, need to check it can come from sstate at all for determinism?
>> +                        remapped = False
>> +                        if newuni == origuni:
>> +                            # Nothing to do, we match, skip code below
>> +                            remapped = True
>> +                        elif tid in self.scenequeue_covered or tid in self.sq_live:
>> +                            # Already ran this setscene task or it running. Report the new taskhash
>> +                            remapped = bb.parse.siggen.report_unihash_equiv(tid, newhash, origuni, newuni, self.rqdata.dataCaches)
>> +                            logger.info("Already covered setscene for %s so ignoring rehash (remap)" % (tid))
> Do we really want this level of logging? 
I appreciate you taking the time out to review the patch series.

For keeping backporting easier while master continues to address hash
equivalence, it seemed responsible to keep patches as they are.

Also for my own sanity, I needed to start collection fixes for hq as I
know we are not finished sorting that out and I feel like there will be
more to come.
> I have not commented on it for 
> master (yet), as I expect it is invaluable for RP & co that are currently 
> working hard on the hash server, but for me as common user of bitbake, 
> this is just noise (and a lot of it). I have a local patch that changes 
> this to logger.debug(1, ...) together with another logger.info("Task %s 
> unihash changed to %s" ...) a few lines earlier to get the cooker UI 
> reasonably back to usable. Also see below.

I will wait for Master for any logging changes made there before
diverging 1.44. The next zeus update which is currently scheduled after
M2. ( Jan/2021) and if hq is still showing signs of being problematic, i
suspect this entire series may wait for more stability from master.

regards,
Armin

>
>> +
>> +                        if not remapped:
>> +                            logger.debug(1, "Task %s hash changes: %s->%s %s->%s" % (tid, orighash, newhash, origuni, newuni))
>> +                            self.rqdata.runtaskentries[tid].hash = newhash
>> +                            self.rqdata.runtaskentries[tid].unihash = newuni
>> +                            changed.add(tid)
>> +
>>                          next |= self.rqdata.runtaskentries[tid].revdeps
>> -                        changed.add(tid)
>>                          total.remove(tid)
>>                          next.intersection_update(total)
>>
>> @@ -2307,18 +2321,11 @@ class RunQueueExecute:
>>                  self.pending_migrations.add(tid)
>>
>>          for tid in self.pending_migrations.copy():
>> -            if tid in self.runq_running:
>> +            if tid in self.runq_running or tid in self.sq_live:
>>                  # Too late, task already running, not much we can do now
>>                  self.pending_migrations.remove(tid)
>>                  continue
>>
>> -            if tid in self.scenequeue_covered or tid in self.sq_live:
>> -                # Already ran this setscene task or it running
>> -                # Potentially risky, should we report this hash as a match?
>> -                logger.info("Already covered setscene for %s so ignoring rehash" % (tid))
>> -                self.pending_migrations.remove(tid)
>> -                continue
>> -
>>              valid = True
>>              # Check no tasks this covers are running
>>              for dep in self.sqdata.sq_covered_tasks[tid]:
>> diff --git a/lib/bb/siggen.py b/lib/bb/siggen.py
>> index e19812b..edf1010 100644
>> --- a/lib/bb/siggen.py
>> +++ b/lib/bb/siggen.py
>> @@ -525,6 +525,32 @@ class SignatureGeneratorUniHashMixIn(object):
>>                  except OSError:
>>                      pass
>>
>> +    def report_unihash_equiv(self, tid, taskhash, wanted_unihash, current_unihash, datacaches):
>> +        try:
>> +            extra_data = {}
>> +            data = self.client().report_unihash_equiv(taskhash, self.method, wanted_unihash, extra_data)
>> +            bb.note('Reported task %s as unihash %s to %s (%s)' % (tid, wanted_unihash, self.server, str(data)))
> This one and ...
>
>> +
>> +            if data is None:
>> +                bb.warn("Server unable to handle unihash report")
>> +                return False
>> +
>> +            finalunihash = data['unihash']
>> +
>> +            if finalunihash == current_unihash:
>> +                bb.note('Task %s unihash %s unchanged by server' % (tid, finalunihash))
>> +            elif finalunihash == wanted_unihash:
>> +                bb.note('Task %s unihash changed %s -> %s as wanted' % (tid, current_unihash, finalunihash))
>> +                self.set_unihash(tid, finalunihash)
>> +                return True
>> +            else:
>> +                # TODO: What to do here?
>> +                bb.note('Task %s unihash reported as unwanted hash %s' % (tid, finalunihash))
> ... and these also seem excessive. I have changed them locally to 
> bb.debug(1, ...) too.
>
>> +        except hashserv.client.HashConnectionError as e:
>> +            bb.warn('Error contacting Hash Equivalence Server %s: %s' % (self.server, str(e)))
>> +
>> +        return False
>>
>>  #
>>  # Dummy class used for bitbake-selftest
>> --
>> 2.7.4
> //Peter
>




^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [1.44 02/18] runqueue/siggen: Allow handling of equivalent hashes
  2019-12-23  8:25   ` Peter Kjellerstedt
  2019-12-23 16:18     ` akuster808
@ 2019-12-28 12:24     ` Richard Purdie
  1 sibling, 0 replies; 22+ messages in thread
From: Richard Purdie @ 2019-12-28 12:24 UTC (permalink / raw)
  To: Peter Kjellerstedt, Armin Kuster, bitbake-devel

On Mon, 2019-12-23 at 08:25 +0000, Peter Kjellerstedt wrote:
> > -----Original Message-----
> > From: bitbake-devel-bounces@lists.openembedded.org <bitbake-devel-
> > bounces@lists.openembedded.org> On Behalf Of Armin Kuster
> > Sent: den 23 december 2019 05:50
> > To: bitbake-devel@lists.openembedded.org
> > Subject: [bitbake-devel] [1.44 02/18] runqueue/siggen: Allow handling of
> > equivalent hashes
> > 
> > From: Richard Purdie <richard.purdie@linuxfoundation.org>
> > 
> > Based on the hashserv's new ability to accept hash mappings, update
> > runqueue
> > to use this through a helper function in siggen.
> > 
> > This addresses problems with meta-extsdk-toolchain and its dependency on
> > gdb-cross which caused errors when building eSDK. See the previous commit
> > for more details.
> > 
> > Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
> > (cherry picked from commit 39098b4ba2133f4d9229a0aa4fcf4c3e1291286a)
> > ---
> >  lib/bb/runqueue.py | 31 +++++++++++++++++++------------
> >  lib/bb/siggen.py   | 26 ++++++++++++++++++++++++++
> >  2 files changed, 45 insertions(+), 12 deletions(-)
> > 
> > diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py
> > index bd7f03f..a869ba5 100644
> > --- a/lib/bb/runqueue.py
> > +++ b/lib/bb/runqueue.py
> > @@ -2283,12 +2283,26 @@ class RunQueueExecute:
> >                          for dep in self.rqdata.runtaskentries[tid].depends:
> >                              procdep.append(dep)
> >                          orighash = self.rqdata.runtaskentries[tid].hash
> > -                        self.rqdata.runtaskentries[tid].hash = bb.parse.siggen.get_taskhash(tid, procdep, self.rqdata.dataCaches[mc_from_tid(tid)])
> > +                        newhash = bb.parse.siggen.get_taskhash(tid, procdep, self.rqdata.dataCaches[mc_from_tid(tid)])
> >                          origuni = self.rqdata.runtaskentries[tid].unihash
> > -                        self.rqdata.runtaskentries[tid].unihash = bb.parse.siggen.get_unihash(tid)
> > -                        logger.debug(1, "Task %s hash changes: %s->%s %s->%s" % (tid, orighash, self.rqdata.runtaskentries[tid].hash, origuni, self.rqdata.runtaskentries[tid].unihash))
> > +                        newuni = bb.parse.siggen.get_unihash(tid)
> > +                        # FIXME, need to check it can come from sstate at all for determinism?
> > +                        remapped = False
> > +                        if newuni == origuni:
> > +                            # Nothing to do, we match, skip code below
> > +                            remapped = True
> > +                        elif tid in self.scenequeue_covered or tid in self.sq_live:
> > +                            # Already ran this setscene task or it running. Report the new taskhash
> > +                            remapped = bb.parse.siggen.report_unihash_equiv(tid, newhash, origuni, newuni, self.rqdata.dataCaches)
> > +                            logger.info("Already covered setscene for %s so ignoring rehash (remap)" % (tid))
> 
> Do we really want this level of logging? I have not commented on it for 
> master (yet), as I expect it is invaluable for RP & co that are currently 
> working hard on the hash server, but for me as common user of bitbake, 
> this is just noise (and a lot of it). I have a local patch that changes 
> this to logger.debug(1, ...) together with another logger.info("Task %s 
> unihash changed to %s" ...) a few lines earlier to get the cooker UI 
> reasonably back to usable. Also see below.

This is a tough one. I appreciate the console is getting noisy,
equally, there are some significant problems with hashequiv and without
this logging we're even more in the dark about what went wrong :(.

We're struggling to figure out what is wrong already and I'd much
rather have logs I can look at and have some idea of what happened
rather than shrugging and saying "dunno".

Whilst right now I'm using this to debug the issues the autobuilder is
showing, if other users run into issues we'll need the same logs. If
someone sends me a log with these entries missing, I will close the bug
as unfixable, I really don't have any other choice.

Fundamentally, we need to sort this out differently so that bitbake
does write a decent log somewhere about what happened even if its not
on the console.

We also need to ensure it *is* on the console on the autobuilder since
those are the logs which are preserved.

I do agree with Armin that we should keep master and zeus with the same
behaviour as to do otherwise will just create more of a mess.

I will likely reduce the noise eventually but only when we're not
hitting issues.

Cheers,

Richard






^ permalink raw reply	[flat|nested] 22+ messages in thread

end of thread, other threads:[~2019-12-28 12:24 UTC | newest]

Thread overview: 22+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2019-12-23  4:50 [1.44 00/18] Patch review Armin Kuster
2019-12-23  4:50 ` [1.44 01/18] hashserv: Add support for equivalent hash reporting Armin Kuster
2019-12-23  4:50 ` [1.44 02/18] runqueue/siggen: Allow handling of equivalent hashes Armin Kuster
2019-12-23  8:25   ` Peter Kjellerstedt
2019-12-23 16:18     ` akuster808
2019-12-28 12:24     ` Richard Purdie
2019-12-23  4:50 ` [1.44 03/18] runqueue: Add extra debugging when locked sigs mismatches occur Armin Kuster
2019-12-23  4:50 ` [1.44 04/18] knotty/uihelper: Switch from pids to tids for Task event management Armin Kuster
2019-12-23  4:50 ` [1.44 05/18] siggen: Avoid taskhash mismatch errors for nostamp tasks when dependencies rehash Armin Kuster
2019-12-23  4:50 ` [1.44 06/18] siggen: Ensure new unihash propagates through the system Armin Kuster
2019-12-23  4:50 ` [1.44 07/18] runqueue: Batch scenequeue updates Armin Kuster
2019-12-23  4:50 ` [1.44 08/18] siggen: Fix performance issue in get_unihash Armin Kuster
2019-12-23  4:50 ` [1.44 09/18] bb.utils.fileslocked: don't leak files if yield throws Armin Kuster
2019-12-23  4:50 ` [1.44 10/18] runqueue: Rework process_possible_migrations() to improve performance Armin Kuster
2019-12-23  4:50 ` [1.44 11/18] runqueue: Fix task mismatch failures from incorrect logic Armin Kuster
2019-12-23  4:50 ` [1.44 12/18] siggen: Split get_tashhash for performance Armin Kuster
2019-12-23  4:50 ` [1.44 13/18] runqueue: Fix sstate task iteration performance Armin Kuster
2019-12-23  4:50 ` [1.44 14/18] runqueue: Optimise task migration code slightly Armin Kuster
2019-12-23  4:50 ` [1.44 15/18] runqueue: Optimise out pointless loop iteration Armin Kuster
2019-12-23  4:50 ` [1.44 16/18] runqueue: Optimise task filtering Armin Kuster
2019-12-23  4:50 ` [1.44 17/18] runqueue: Only call into the migrations function if migrations active Armin Kuster
2019-12-23  4:50 ` [1.44 18/18] lib/bb: Optimise out debug messages from cooker Armin Kuster

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.