Skip to contentSkip to conversation

data_smart.py (mostly): Variable and include tracking!

RFC PATCH In review Peter Seebach 1 participant 4 messages May 18, 2012

lore
Share & tools
lore
#0 lore raw

cover data_smart.py (mostly): Variable and include tracking!

This is a first pass at allowing us to answer that vexing question:

Where the heck did that value come from?

The complexity of bitbake's variable assignment means that even if you had a complete list of the lines being processed in order, you might need a few tries to figure out why a variable is set to what it is. When debugging, you might want to know what it would have been otherwise, too; knowing that a given ?= is processed after a +=, for instance, could save you a great deal of trouble. To solve this, we add two pieces of functionality to "bitbake -e".

The first is a list of the .conf/.inc files that were parsed, in order; the list shows included files indented under the thing that included them, making it easier to see not just what got processed, but why it got processed.

The second is a list of all the operations performed on each value, in order, citing to the file and line number where they happened (whenever possible). So, for instance, say I want to know how SSTATETASKS got its value. The output of "bitbake -e" now says:

# SSTATETASKS [4]
# append /home/seebs/poky/meta/classes/staging.bbclass:105:
# < do_populate_sysroot>
# append /home/seebs/poky/meta/classes/package.bbclass:1750:
# < do_populate_sysroot do_package>
# append /home/seebs/poky/meta/classes/package_rpm.bbclass:1112:
# < do_populate_sysroot do_package do_package_write_rpm>
# append /home/seebs/poky/meta/classes/license.bbclass:380:
# < do_populate_sysroot do_package do_package_write_rpm do_populate_lic>
#
# SSTATETASKS= do_populate_sysroot do_package do_package_write_rpm do_populate_lic

Wait, staging.bbclass? I don't remember asking for that. Let's go look at the include history:

# /home/seebs/poky/meta/classes/base.bbclass includes:
#   /home/seebs/poky/meta/classes/patch.bbclass includes:
#     /home/seebs/poky/meta/classes/terminal.bbclass
#   /home/seebs/poky/meta/classes/staging.bbclass

So this tells me that staging.bbclass was included from base.bbclass. Yay! Mystery is solved. Everything is working because it's doing what it is supposed to do. :)

The following changes since commit f8bf4499549f978ce7c93bc088a66f74cd751e2c:
Martin Jansa (1):
setup.py: fix path for bitbake-selftest

are available in the git repository at:

git://git.yoctoproject.org/poky-contrib seebs/tracking
http://git.yoctoproject.org/cgit.cgi/poky-contrib/log/?h=seebs/tracking

Peter Seebach (2):
data_smart.py: Provide (optional) logging of variable modifications data_smart.py: Track configuration file inclusions

 lib/bb/cooker.py                   |    4 +-
 lib/bb/data.py                     |   46 +++++++++++--
 lib/bb/data_smart.py               |  128 +++++++++++++++++++++++++++--------
 lib/bb/parse/__init__.py           |    8 ++-
 lib/bb/parse/ast.py                |   89 +++++++++++++------------
 lib/bb/parse/parse_py/BBHandler.py |    8 +-
 lib/bb/siggen.py                   |    2 +-
 7 files changed, 198 insertions(+), 87 deletions(-)
#1 lore raw

RFC PATCH 1/2 data_smart.py: Provide (optional) logging of variable modifications

This is very preliminary, and probably not very good, but it provides a much-wanted feature: An explanation of how variables got their current values.

How it works:

1. We create a history dict in the data_smart object, the members of which are lists of tuples. It's three, count them, THREE unrelated data types in a single object!
2. There is an eventLog(...) function which allows recording things which happen to variables.
3. All over the place, tons of setVar and related functions are updated with two optional arguments, filename and lineno.
4. We log pretty much everything if logging is enabled.
5. You can query the history of a thing with data.getHistory(var)

Tracking must be specifically turned on. If it's not, the history object is a single empty table (cheap) and the calls to eventLog() and extra argument passing are also probably quite cheap. As a proof of concept, the showEnvironment function used by bitbake -e now uses this if available.

---
 lib/bb/cooker.py                   |    4 +-
 lib/bb/data.py                     |   30 +++++++++---
 lib/bb/data_smart.py               |   91 ++++++++++++++++++++++++-----------
 lib/bb/parse/__init__.py           |    2 +-
 lib/bb/parse/ast.py                |   89 +++++++++++++++++++----------------
 lib/bb/parse/parse_py/BBHandler.py |    8 ++--
 lib/bb/siggen.py                   |    2 +-
 7 files changed, 141 insertions(+), 85 deletions(-)
lib/bb/cooker.py +3 -1
index dea0aad..76104ef 100644
@@ -825,6 +825,8 @@ class BBCooker:
 
     def parseConfigurationFiles(self, prefiles, postfiles):
         data = self.configuration.data
+        if self.configuration.show_environment:
+            data.enableTracking()
         bb.parse.init_parser(data)
 
         # Parse files for loading *before* bitbake.conf and any includes
@@ -871,7 +873,7 @@ class BBCooker:
         bb.codeparser.parser_cache_init(data)
         bb.event.fire(bb.event.ConfigParsed(), data)
         bb.parse.init_parser(data)
-        data.setVar('BBINCLUDED',bb.parse.get_file_depends(data))
+        data.setVar('BBINCLUDED',bb.parse.get_file_depends(data), 'cooker.py', 'N/A')
         self.configuration.data = data
         self.configuration.data_hash = data.get_hash()
 
lib/bb/data.py +22 -8
index c0636e1..74efc5d 100644
@@ -74,14 +74,21 @@ def createCopy(source):
     """
     return source.createCopy()
 
+# These are used in dataSmart, here as protection against KeyErrors.
+def enableTracking():
+    pass
+
+def disableTracking():
+    pass
+
 def initVar(var, d):
     """Non-destructive var init for data structure"""
     d.initVar(var)
 
 
-def setVar(var, value, d):
+def setVar(var, value, d, filename = 'unknown', lineno = 'N/A'):
     """Set a variable to a given value"""
-    d.setVar(var, value)
+    d.setVar(var, value, filename, lineno)
 
 
 def getVar(var, d, exp = 0):
@@ -89,17 +96,17 @@ def getVar(var, d, exp = 0):
     return d.getVar(var, exp)
 
 
-def renameVar(key, newkey, d):
+def renameVar(key, newkey, d, filename = 'unknown', lineno = 'N/A'):
     """Renames a variable from key to newkey"""
-    d.renameVar(key, newkey)
+    d.renameVar(key, newkey, filename, lineno)
 
-def delVar(var, d):
+def delVar(var, d, filename = 'unknown', lineno = 'N/A'):
     """Removes a variable from the data set"""
-    d.delVar(var)
+    d.delVar(var, filename, lineno)
 
-def setVarFlag(var, flag, flagvalue, d):
+def setVarFlag(var, flag, flagvalue, d, filename = 'unknown', lineno = 'N/A'):
     """Set a flag for a given variable to a given value"""
-    d.setVarFlag(var, flag, flagvalue)
+    d.setVarFlag(var, flag, flagvalue, filename, lineno)
 
 def getVarFlag(var, flag, d):
     """Gets given flag from given var"""
@@ -195,6 +202,13 @@ def emit_var(var, o=sys.__stdout__, d = init(), all=False):
 
     if all:
         commentVal = re.sub('\n', '\n#', str(oval))
+        history = d.getHistory(var)
+        if history:
+            o.write('#\n# %s [%d]\n' % (var, len(history)))
+            for events in history:
+                events = (events[0], events[1], events[2], re.sub('\n', '\n#     ', str(events[3])))
+                o.write('#   %s %s:%s:\n#     <%s>\n' % events)
+            o.write('#\n')
         o.write('# %s=%s\n' % (var, commentVal))
 
     if (var.find("-") != -1 or var.find(".") != -1 or var.find('{') != -1 or var.find('}') != -1 or var.find('+') != -1) and not all:
lib/bb/data_smart.py +62 -29

231 lines not on this page · raw message

lib/bb/parse/__init__.py +1 -1
index 7b9c47e..3c3feee 100644
@@ -75,7 +75,7 @@ def mark_dependency(d, f):
         f = "%s/%s" % (os.getcwd(), f[2:])
     deps = d.getVar('__depends') or set()
     deps.update([(f, cached_mtime(f))])
-    d.setVar('__depends', deps)
+    d.setVar('__depends', deps, f, 'N/A')
 
 def supports(fn, data):
     """Returns true if we have a handler for this file, false otherwise"""
lib/bb/parse/ast.py +48 -41

232 lines not on this page · raw message

lib/bb/parse/parse_py/BBHandler.py +4 -4
index 815bce1..44d7a82 100644
@@ -78,7 +78,7 @@ def inherit(files, fn, lineno, d):
         if not file in __inherit_cache:
             logger.log(logging.DEBUG -1, "BB %s:%d: inheriting %s", fn, lineno, file)
             __inherit_cache.append( file )
-            data.setVar('__inherit_cache', __inherit_cache, d)
+            data.setVar('__inherit_cache', __inherit_cache, d, fn, lineno)
             include(fn, file, lineno, d, "inherit")
             __inherit_cache = data.getVar('__inherit_cache', d) or []
 
@@ -129,7 +129,7 @@ def handle(fn, d, include):
         __inherit_cache = data.getVar('__inherit_cache', d) or []
         if not fn in __inherit_cache:
             __inherit_cache.append(fn)
-            data.setVar('__inherit_cache', __inherit_cache, d)
+            data.setVar('__inherit_cache', __inherit_cache, d, fn, 'N/A')
 
     if include != 0:
         oldfile = data.getVar('FILE', d)
@@ -146,7 +146,7 @@ def handle(fn, d, include):
 
     # DONE WITH PARSING... time to evaluate
     if ext != ".bbclass":
-        data.setVar('FILE', abs_fn, d)
+        data.setVar('FILE', abs_fn, d, fn, 'N/A')
 
     statements.eval(d)
 
@@ -157,7 +157,7 @@ def handle(fn, d, include):
             return ast.multi_finalize(fn, d)
 
     if oldfile:
-        d.setVar("FILE", oldfile)
+        d.setVar("FILE", oldfile, fn, 'N/A')
 
     # we have parsed the bb class now
     if ext == ".bbclass" or ext == ".inc":
lib/bb/siggen.py +1 -1
index 5a0b80e..d1babf1 100644
@@ -137,7 +137,7 @@ class SignatureGeneratorBasic(SignatureGenerator):
         #    self.dump_sigtask(fn, task, d.getVar("STAMP", True), False)
 
         for task in taskdeps:
-            d.setVar("BB_BASEHASH_task-%s" % task, self.basehash[fn + "." + task])
+            d.setVar("BB_BASEHASH_task-%s" % task, self.basehash[fn + "." + task], 'siggen.py', 'N/A')
 
     def rundep_check(self, fn, recipename, task, dep, depname, dataCache):
         # Return True if we should keep the dependency, False to drop it
Signature · 1 line
1.7.0.4
#2 lore raw

Re: [RFC PATCH 1/2] data_smart.py: Provide (optional) logging of variable modifications

Quoted 3 lines · On Fri, 18 May 2012 12:27:39 -0500 Peter Seebach <[email protected]>…
(quoted diff) +1 -1
-        data.setVar('BBINCLUDED',bb.parse.get_file_depends(data))
+        data.setVar('BBINCLUDED',bb.parse.get_file_depends(data),

'cooker.py', 'N/A')

kergoth points out, quite cleverly, that most of the changes that look like this could be removed. His suggestion: Instead of defaulting to "unknown" for the optional arguments, default to "use the Python stack inspection to identify the caller."

This seems like a really good idea to me, because it allows us to get meaningful data in nearly all the cases, while preserving the option of specifying other values when, say, parsing config files.

Any objections to that as a plan for a v2?

-s

Signature · 1 line
Listen, get this.  Nobody with a good compiler needs to be justified.
#3 lore raw

RFC PATCH 2/2 data_smart.py: Track configuration file inclusions

In reply to Peter Seebach

This is a preliminary attempt to create a structured representation of the processing of include files. It ignores line numbers because they're meaningless. It could probably be updated to, say, distinguish between includes and requires. Output is added to the output of bitbake -e.

---
 lib/bb/data.py           |   16 ++++++++++++++++
 lib/bb/data_smart.py     |   41 ++++++++++++++++++++++++++++++++++++++---
 lib/bb/parse/__init__.py |    6 +++++-
 3 files changed, 59 insertions(+), 4 deletions(-)
lib/bb/data.py +16 -0
index 74efc5d..5ad7862 100644
@@ -246,10 +246,26 @@ def emit_env(o=sys.__stdout__, d = init(), all=False):
     isfunc = lambda key: bool(d.getVarFlag(key, "func"))
     keys = sorted((key for key in d.keys() if not key.startswith("__")), key=isfunc)
     grouped = groupby(keys, isfunc)
+    # Include history!
+    if d.tracking():
+        o.write('#\n# INCLUDE HISTORY:\n#\n')
+        emit_history(o, d.getIncludeHistory())
+        
     for isfunc, keys in grouped:
         for key in keys:
             emit_var(key, o, d, all and not isfunc) and o.write('\n')
 
+def emit_history(o, h, depth = 0):
+    if not h:
+        return
+    for event in h:
+        o.write("# %*s%s" % (depth * 2, "", event[0]))
+        if event[1]:
+            o.write(" includes:\n")
+            emit_history(o, event[1], depth + 1)
+        else:
+            o.write("\n")
+
 def exported_keys(d):
     return (key for key in d.keys() if not key.startswith('__') and
                                       d.getVarFlag(key, 'export') and
lib/bb/data_smart.py +38 -3

65 lines not on this page · raw message

lib/bb/parse/__init__.py +5 -1
index 3c3feee..26b501b 100644
@@ -88,7 +88,11 @@ def handle(fn, data, include = 0):
     """Call the handler that is appropriate for this file"""
     for h in handlers:
         if h['supports'](fn, data):
-            return h['handle'](fn, data, include)
+            data.includeLog(fn)
+            try:
+                return h['handle'](fn, data, include)
+            finally:
+                data.includeLogDone(fn)
     raise ParseError("not a BitBake file", fn)
 
 def init(fn, data):
Signature · 1 line
1.7.0.4