Patchwork [bitbake-devel,0/2] Variable tracking: Cleaned up and rebased.

login
register
mail settings
Submitter Peter Seebach
Date Jan. 12, 2013, 1:40 a.m.
Message ID <cover.1357954043.git.peter.seebach@windriver.com>
Download mbox
Permalink /patch/42531/
State New
Headers show

Pull-request

git://git.yoctoproject.org/poky-contrib seebs/incvar

Comments

Peter Seebach - Jan. 12, 2013, 1:40 a.m.
This is the much-famed "variable tracking" patch. Rebased against current
bitbake, fixed a couple of things.

WHAT IT DOES:

        $ bitbake -e > variable_history

        $ cat variable_history
        #
        # INCLUDE HISTORY:
        #
        # /home/seebs/oe-core/build/conf/bblayers.conf
        # /home/seebs/oe-core/meta/conf/layer.conf
        # conf/bitbake.conf includes:
        #   /home/seebs/oe-core/meta/conf/abi_version.conf
        #   conf/site.conf
        #   conf/auto.conf
        #   /home/seebs/oe-core/build/conf/local.conf
        [...]
        # $prefix [2 operations]
        #   exported conf/bitbake.conf:17
        #     [export] "1"
        #   set conf/bitbake.conf:17
        #     "/usr"
        # computed:
        #   "/usr"
        export prefix="/usr"
        [...]

This can get pretty useful if you're trying to find out, say, where
the -m32 came from in TUNE_CCARGS:

        # $TUNE_CCARGS [6 operations]
        #   set conf/bitbake.conf:105
        #     [defaultval] ""
        #   set conf/bitbake.conf:106
        #     [vardepvalue] "${TUNE_CCARGS}"
        #   append /home/seebs/oe-core/meta/conf/machine/include/ia32/arch-ia32.inc:16
        #     "${@bb.utils.contains("TUNE_FEATURES", "m32", "-m32", "", d)}"
        #   append /home/seebs/oe-core/meta/conf/machine/include/ia32/arch-ia32.inc:24
        #     "${@bb.utils.contains("TUNE_FEATURES", "mx32", "-mx32", "", d)}"
        #   append /home/seebs/oe-core/meta/conf/machine/include/ia32/arch-ia32.inc:32
        #     "${@bb.utils.contains("TUNE_FEATURES", "m64", "-m64", "", d)}"
        #   append /home/seebs/oe-core/meta/conf/machine/include/tune-i586.inc:7
        #     "${@bb.utils.contains("TUNE_FEATURES", "i586", "-march=i586", "", d)}"
        # computed:
        #   " ${@bb.utils.contains("TUNE_FEATURES", "m32", "-m32", "", d)} ${@bb.utils.contains("TUNE_FEATURES", "mx32", "-mx32", "", d)} ${@bb.utils.contains("TUNE_FEATURES", "m64", "-m64", "", d)} ${@bb.utils.contains("TUNE_FEATURES", "i586", "-march=i586", "", d)}"
        TUNE_CCARGS="-m32   -march=i586"
        #

The cleanup since the last version is pretty minor, but there was one real
bug: If any part of a variable's history showed a modification from Python
code (with a function name) rather than from the parser, the variable's
value would be displayed as though it were a function. Whoops.

The output for renames is now much more useful than it was before, though:

# $SECTION_${PN}-dbg [2 operations]
#   set conf/bitbake.conf:316
#     "devel"
#   rename (to) data.py:161 [expandKeys]
#     "SECTION_core-image-minimal-dbg"
# computed:
#   "None"

and

# $SECTION_core-image-minimal-dbg
#   rename from SECTION_${PN}-dbg data.py:161 [expandKeys]
#     "devel"
SECTION_core-image-minimal-dbg="devel"

I remain a little unhappy with the loginfo stuff, in particular the
possible clash between keys in loginfo and non-keyword arguments, but
I can't really think of a way to make it definitely better, and the
much-less-intrusive usage strikes me as a big enough improvement to
justify it. (Picking different names for the keyword arguments would
reduce clashes, and also legibility in cases where they're being
specified.)

The following changes since commit dee7decf87dfa8cb966fe40846d27f3e6ab1846b:
  Richard Purdie (1):
        build.py: Fix traceback when there are no dependencies

are available in the git repository at:

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

Peter Seebach (2):
  data_smart.py and friends: Track file inclusions for bitbake -e
  data_smart.py and friends: Track variable history

 lib/bb/cooker.py                   |   15 ++-
 lib/bb/data.py                     |   38 +++++-
 lib/bb/data_smart.py               |  250 ++++++++++++++++++++++++++++++++----
 lib/bb/parse/__init__.py           |    3 +-
 lib/bb/parse/ast.py                |   25 +++-
 lib/bb/parse/parse_py/BBHandler.py |    6 +-
 6 files changed, 299 insertions(+), 38 deletions(-)
Richard Purdie - Jan. 16, 2013, 5:54 p.m.
On Fri, 2013-01-11 at 19:40 -0600, Peter Seebach wrote:
> This is the much-famed "variable tracking" patch. Rebased against current
> bitbake, fixed a couple of things.
> 
> WHAT IT DOES:
> 
>         $ bitbake -e > variable_history
> 
>         $ cat variable_history
>         #
>         # INCLUDE HISTORY:
>         #
>         # /home/seebs/oe-core/build/conf/bblayers.conf
>         # /home/seebs/oe-core/meta/conf/layer.conf
>         # conf/bitbake.conf includes:
>         #   /home/seebs/oe-core/meta/conf/abi_version.conf
>         #   conf/site.conf
>         #   conf/auto.conf
>         #   /home/seebs/oe-core/build/conf/local.conf
>         [...]
>         # $prefix [2 operations]
>         #   exported conf/bitbake.conf:17
>         #     [export] "1"
>         #   set conf/bitbake.conf:17
>         #     "/usr"
>         # computed:
>         #   "/usr"
>         export prefix="/usr"
>         [...]
> 
> This can get pretty useful if you're trying to find out, say, where
> the -m32 came from in TUNE_CCARGS:
> 
>         # $TUNE_CCARGS [6 operations]
>         #   set conf/bitbake.conf:105
>         #     [defaultval] ""
>         #   set conf/bitbake.conf:106
>         #     [vardepvalue] "${TUNE_CCARGS}"
>         #   append /home/seebs/oe-core/meta/conf/machine/include/ia32/arch-ia32.inc:16
>         #     "${@bb.utils.contains("TUNE_FEATURES", "m32", "-m32", "", d)}"
>         #   append /home/seebs/oe-core/meta/conf/machine/include/ia32/arch-ia32.inc:24
>         #     "${@bb.utils.contains("TUNE_FEATURES", "mx32", "-mx32", "", d)}"
>         #   append /home/seebs/oe-core/meta/conf/machine/include/ia32/arch-ia32.inc:32
>         #     "${@bb.utils.contains("TUNE_FEATURES", "m64", "-m64", "", d)}"
>         #   append /home/seebs/oe-core/meta/conf/machine/include/tune-i586.inc:7
>         #     "${@bb.utils.contains("TUNE_FEATURES", "i586", "-march=i586", "", d)}"
>         # computed:
>         #   " ${@bb.utils.contains("TUNE_FEATURES", "m32", "-m32", "", d)} ${@bb.utils.contains("TUNE_FEATURES", "mx32", "-mx32", "", d)} ${@bb.utils.contains("TUNE_FEATURES", "m64", "-m64", "", d)} ${@bb.utils.contains("TUNE_FEATURES", "i586", "-march=i586", "", d)}"
>         TUNE_CCARGS="-m32   -march=i586"
>         #
> 
> The cleanup since the last version is pretty minor, but there was one real
> bug: If any part of a variable's history showed a modification from Python
> code (with a function name) rather than from the parser, the variable's
> value would be displayed as though it were a function. Whoops.
> 
> The output for renames is now much more useful than it was before, though:
> 
> # $SECTION_${PN}-dbg [2 operations]
> #   set conf/bitbake.conf:316
> #     "devel"
> #   rename (to) data.py:161 [expandKeys]
> #     "SECTION_core-image-minimal-dbg"
> # computed:
> #   "None"
> 
> and
> 
> # $SECTION_core-image-minimal-dbg
> #   rename from SECTION_${PN}-dbg data.py:161 [expandKeys]
> #     "devel"
> SECTION_core-image-minimal-dbg="devel"
> 
> I remain a little unhappy with the loginfo stuff, in particular the
> possible clash between keys in loginfo and non-keyword arguments, but
> I can't really think of a way to make it definitely better, and the
> much-less-intrusive usage strikes me as a big enough improvement to
> justify it. (Picking different names for the keyword arguments would
> reduce clashes, and also legibility in cases where they're being
> specified.)
> 
> The following changes since commit dee7decf87dfa8cb966fe40846d27f3e6ab1846b:
>   Richard Purdie (1):
>         build.py: Fix traceback when there are no dependencies
> 
> are available in the git repository at:
> 
>   git://git.yoctoproject.org/poky-contrib seebs/incvar
>   http://git.yoctoproject.org/cgit.cgi/poky-contrib/log/?h=seebs/incvar
> 
> Peter Seebach (2):
>   data_smart.py and friends: Track file inclusions for bitbake -e
>   data_smart.py and friends: Track variable history

I *really* want to take these, however I did want to check performance:

Before:

$ time bitbake core-image-sato -e
real	0m8.034s
$ time bitbake -p
real	0m12.220s
user	3m3.887s

After:

$ time bitbake core-image-sato -e
real	0m50.267s
$ time bitbake -p
real	0m14.607s
user	3m55.179s


The 50s seems a touch excessive and it looks like a 20% parsing hit even
when unused :(. Note the overall parsing times on this machine are fast
as its running 24 in parallel. I'm going to try and figure out what is
going on tomorrow as I've fixed a lot of this kind of thing in the past
but wanted to mention it...

Cheers,

Richard
Richard Purdie - Jan. 16, 2013, 5:59 p.m.
On Wed, 2013-01-16 at 17:54 +0000, Richard Purdie wrote:
> I *really* want to take these, however I did want to check performance:
> 
> Before:
> 
> $ time bitbake core-image-sato -e
> real	0m8.034s
> $ time bitbake -p
> real	0m12.220s
> user	3m3.887s
> 
> After:
> 
> $ time bitbake core-image-sato -e
> real	0m50.267s
> $ time bitbake -p
> real	0m14.607s
> user	3m55.179s
> 
> 
> The 50s seems a touch excessive and it looks like a 20% parsing hit even
> when unused :(. Note the overall parsing times on this machine are fast
> as its running 24 in parallel. I'm going to try and figure out what is
> going on tomorrow as I've fixed a lot of this kind of thing in the past
> but wanted to mention it...

For those wanting to play:

bitbake core-image-sato -e -P

and looking at profile.log.processed shows 48 *million* calls to
deepcopy. That is a big clue to the problem.

Cheers,

Richard
Peter Seebach - Jan. 16, 2013, 6:01 p.m.
On Wed, 16 Jan 2013 17:54:58 +0000
Richard Purdie <richard.purdie@linuxfoundation.org> wrote:

> I *really* want to take these, however I did want to check
> performance:

Oh, good thought.

> $ time bitbake core-image-sato -e
> real	0m8.034s
> $ time bitbake -p
> real	0m12.220s
> user	3m3.887s
 
> After:
 
> $ time bitbake core-image-sato -e
> real	0m50.267s
> $ time bitbake -p
> real	0m14.607s
> user	3m55.179s

Hmm. That doesn't totally surprise me.
 
> The 50s seems a touch excessive and it looks like a 20% parsing hit
> even when unused :(. Note the overall parsing times on this machine
> are fast as its running 24 in parallel. I'm going to try and figure
> out what is going on tomorrow as I've fixed a lot of this kind of
> thing in the past but wanted to mention it...

The 50s seems... not entirely surprsing. I don't know that much about
how Python does stuff, but in practice we end up with a LOT of deep
copies of structures floating around because there are a ton of data
copies; without these, finalize information gets duplicated and things
go pretty wrong.

My intuition is that the stack backtrace thing is probably expensive,
and might be noticably reduced by manually passing in the
likely-missing values in cases where we know what they are, so it's
less likely that any backtracing has to happen.

-s