sstate/staging: Batch log messages for performance

According to profile data, repeated calls to bb.debug and bb.note in
the extend_recipe_sysroot() codepath were accounting for 75% of the time
(1.5s) in calls from tasks like do_image_complete.

This batches up the log messages into one call into the logging system
which gives similar behaviour to disabling the logging but retains the
debug information.

Since setscene_depvalid is also called from bitbake's setscene code,
we have to be a little creative with the function parameters and leave
the other debug output mechanism in place. This should hopefully
speed up recipe specific sysroots.

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>

2 files changed, 17 insertions, 8 deletions

diff --git a/meta/classes/sstate.bbclass b/meta/classes/sstate.bbclass
index aeb7466d35..ada6fe5986 100644
--- a/meta/classes/sstate.bbclass
+++ b/meta/classes/sstate.bbclass
@@ -909,13 +909,19 @@ def sstate_checkhashes(sq_fn, sq_task, sq_hash, sq_hashfn, d, siginfo=False):
 
 BB_SETSCENE_DEPVALID = "setscene_depvalid"
 
-def setscene_depvalid(task, taskdependees, notneeded, d):
+def setscene_depvalid(task, taskdependees, notneeded, d, log=None):
     # taskdependees is a dict of tasks which depend on task, each being a 3 item list of [PN, TASKNAME, FILENAME]
     # task is included in taskdependees too
     # Return - False - We need this dependency
     #        - True - We can skip this dependency
 
-    bb.debug(2, "Considering setscene task: %s" % (str(taskdependees[task])))
+    def logit(msg, log):
+        if log is not None:
+            log.append(msg)
+        else:
+            bb.debug(2, msg)
+
+    logit("Considering setscene task: %s" % (str(taskdependees[task])), log)
 
     def isNativeCross(x):
         return x.endswith("-native") or "-cross-" in x or "-crosssdk" in x or x.endswith("-cross")
@@ -933,7 +939,7 @@ def setscene_depvalid(task, taskdependees, notneeded, d):
         return True
 
     for dep in taskdependees:
-        bb.debug(2, "  considering dependency: %s" % (str(taskdependees[dep])))
+        logit("  considering dependency: %s" % (str(taskdependees[dep])), log)
         if task == dep:
             continue
         if dep in notneeded:
@@ -987,7 +993,7 @@ def setscene_depvalid(task, taskdependees, notneeded, d):
 
 
         # Safe fallthrough default
-        bb.debug(2, " Default setscene dependency fall through due to dependency: %s" % (str(taskdependees[dep])))
+        logit(" Default setscene dependency fall through due to dependency: %s" % (str(taskdependees[dep])), log)
         return False
     return True
 
diff --git a/meta/classes/staging.bbclass b/meta/classes/staging.bbclass
index b9c84a4057..35e53fe2b2 100644
--- a/meta/classes/staging.bbclass
+++ b/meta/classes/staging.bbclass
@@ -441,6 +441,7 @@ python extend_recipe_sysroot() {
     bb.note("Direct dependencies are %s" % str(configuredeps))
     #bb.note(" or %s" % str(start))
 
+    msgbuf = []
     # Call into setscene_depvalid for each sub-dependency and only copy sysroot files
     # for ones that would be restored from sstate.
     done = list(start)
@@ -455,19 +456,21 @@ python extend_recipe_sysroot() {
                 taskdeps = {}
                 taskdeps[dep] = setscenedeps[dep][:2]
                 taskdeps[datadep] = setscenedeps[datadep][:2]
-                retval = setscene_depvalid(datadep, taskdeps, [], d)
+                retval = setscene_depvalid(datadep, taskdeps, [], d, msgbuf)
                 if retval:
-                    bb.note("Skipping setscene dependency %s for installation into the sysroot" % datadep)
+                    msgbuf.append("Skipping setscene dependency %s for installation into the sysroot")
                     continue
                 done.append(datadep)
                 new.append(datadep)
                 if datadep not in configuredeps and setscenedeps[datadep][1] == "do_populate_sysroot":
                     configuredeps.append(datadep)
-                    bb.note("Adding dependency on %s" % setscenedeps[datadep][0])
+                    msgbuf.append("Adding dependency on %s" % setscenedeps[datadep][0])
                 else:
-                    bb.note("Following dependency on %s" % setscenedeps[datadep][0])
+                    msgbuf.append("Following dependency on %s" % setscenedeps[datadep][0])
         next = new
 
+    bb.note("\n".join(msgbuf))
+
     stagingdir = d.getVar("STAGING_DIR")
     recipesysroot = d.getVar("RECIPE_SYSROOT")
     recipesysrootnative = d.getVar("RECIPE_SYSROOT_NATIVE")