bitbake: providers/runqueue/taskdata: Optimise logger.debug calls

A run of "bitbake bash -c unpack" when the task has already been
completed resulted in about 9000 calls to logger.debug(). With this
patch which comments out some noisy/less usefull logging and moves
other logging calls outside loops, this number is reduced to 1000
calls. This results in cleaner logs and gives a small but
measurable 0.15s speedup. The log size dropped from 900kb to 160kb.

(Bitbake rev: d2677f084fe1d8846db77d89ef5e6ffb18dc171a)

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

bitbake/lib/bb/providers.py

@@ -325,7 +325,7 @@ def filterProvidersRunTime(providers, item, cfgData, dataCache):
         provides = dataCache.pn_provides[pn]
         for provide in provides:
             prefervar = cfgData.getVar('PREFERRED_PROVIDER_%s' % provide, True)
-            logger.debug(1, "checking PREFERRED_PROVIDER_%s (value %s) against %s", provide, prefervar, pns.keys())
+            #logger.debug(1, "checking PREFERRED_PROVIDER_%s (value %s) against %s", provide, prefervar, pns.keys())
             if prefervar in pns and pns[prefervar] not in preferred:
                 var = "PREFERRED_PROVIDER_%s = %s" % (provide, prefervar)
                 logger.verbose("selecting %s to satisfy runtime %s due to %s", prefervar, item, var)

bitbake/lib/bb/runqueue.py

@@ -481,7 +481,7 @@ class RunQueueData:
             fn = taskData.fn_index[fnid]
             task_deps = self.dataCache.task_deps[fn]
 
-            logger.debug(2, "Processing %s:%s", fn, taskData.tasks_name[task])
+            #logger.debug(2, "Processing %s:%s", fn, taskData.tasks_name[task])
 
             if fnid not in taskData.failed_fnids:
 

bitbake/lib/bb/taskdata.py

@@ -207,23 +207,29 @@ class TaskData:
         if not fnid in self.depids:
             dependids = {}
             for depend in dataCache.deps[fn]:
-                logger.debug(2, "Added dependency %s for %s", depend, fn)
                 dependids[self.getbuild_id(depend)] = None
             self.depids[fnid] = dependids.keys()
+            logger.debug(2, "Added dependencies %s for %s", str(dataCache.deps[fn]), fn)
 
         # Work out runtime dependencies
         if not fnid in self.rdepids:
             rdependids = {}
             rdepends = dataCache.rundeps[fn]
             rrecs = dataCache.runrecs[fn]
+            rdependlist = []
+            rreclist = []
             for package in rdepends:
                 for rdepend in rdepends[package]:
-                    logger.debug(2, "Added runtime dependency %s for %s", rdepend, fn)
+                    rdependlist.append(rdepend)
                     rdependids[self.getrun_id(rdepend)] = None
             for package in rrecs:
                 for rdepend in rrecs[package]:
-                    logger.debug(2, "Added runtime recommendation %s for %s", rdepend, fn)
+                    rreclist.append(rdepend)
                     rdependids[self.getrun_id(rdepend)] = None
+            if rdependlist:
+                logger.debug(2, "Added runtime dependencies %s for %s", str(rdependlist), fn)
+            if rreclist:
+                logger.debug(2, "Added runtime recommendations %s for %s", str(rreclist), fn)
             self.rdepids[fnid] = rdependids.keys()
 
         for dep in self.depids[fnid]: