[PATCH 0/4] script to run build tests and collect time metrics

[PATCH 0/4] script to run build tests and collect time metrics

[Stefan Stanacar]

Hello,

This script runs a series of standard tests and collects some metrics
(wall clock and size of tmp/). It takes care of dropping vm caches
(for which it need sudo access) and doing a fetchall first.
It uses /usr/bin/time to measure the wall clock for builds (not bash
internal time command).

The metrics collected are:
* time bitbake core-image-sato and size of tmp/ dir without sstate
* time bitbake virtual/kernel
* time bitbake core-image-sato and size of tmp/ without sstate but with rm_work enabled
* time bitbake core-image-sato -c rootfs with sstate
* three parsing time metrics (bitbake -p) with and without tmp/cache. 

The results are collected in build-perf-test/globalres.log for all commits
that it has run, and in a separate folder for ech run (called results-<rev>-<date>)
This is the same script used to collect the results for:
https://wiki.yoctoproject.org/wiki/Performance_Test#1.4_Perfomance_Data
It's still a work in progress and needs some improvements but it should be a good starting point.

Regards,
Stefan

The following changes since commit 2f4fe1ee111a3dff68ac1cea6f3f6767cd6fe4eb:

  bitbake: hob: Search strings and results should be persistent (2013-03-29 10:41:25 +0000)

are available in the git repository at:

  git://git.yoctoproject.org/poky-contrib stefans/perf-test
  http://git.yoctoproject.org/cgit.cgi/poky-contrib/log/?h=stefans/perf-test

Stefan Stanacar (4):
  scripts/contrib/build-perf-test.sh: add a script for build performance
    tracking
  scripts/contrib/build-perf-test.sh: add a global results file
  scripts/contrib/build-perf-test.sh: add option to allow cherry-picking
    of fix revisions
  scripts/contrib/build-perf-test.sh: add timings for bitbake -p

 scripts/contrib/build-perf-test.sh | 348 +++++++++++++++++++++++++++++++++++++
 1 file changed, 348 insertions(+)
 create mode 100755 scripts/contrib/build-perf-test.sh

-- 
1.8.1.4

[PATCH 1/4] scripts/contrib/build-perf-test.sh: add a script for build performance tracking

[Stefan Stanacar]

This script runs a series of builds (core-image-sato by default) with
and without sstate cache and collects some metrics (time and size currently).
It takes a commit as argument  (-c <rev>) and measures wall clock for
bitbake core-image-sato and virtual/kernel.

Signed-off-by: Stefan Stanacar <stefanx.stanacar@intel.com>
---
 scripts/contrib/build-perf-test.sh | 301 +++++++++++++++++++++++++++++++++++++
 1 file changed, 301 insertions(+)
 create mode 100755 scripts/contrib/build-perf-test.sh

diff --git a/scripts/contrib/build-perf-test.sh b/scripts/contrib/build-perf-test.sh
new file mode 100755
index 0000000..2d70cfa
--- /dev/null
+++ b/scripts/contrib/build-perf-test.sh
@@ -0,0 +1,301 @@
+#!/bin/bash
+#
+# This script runs a series of tests  (with and without sstate) and reports build time (and tmp/ size)
+# 
+# Build performance test script
+#
+# Copyright 2013 Intel Corporation
+#
+# This program is free software; you can redistribute it and/or modify
+# it under the terms of the GNU General Public License as published by
+# the Free Software Foundation; either version 2 of the License, or
+# (at your option) any later version.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with this program; if not, write to the Free Software
+# Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
+#
+#
+# AUTHORS:
+# Stefan Stanacar <stefanx.stanacar@intel.com>
+
+
+ME=$(basename $0)
+
+#
+# usage and setup
+#
+
+usage () {
+cat << EOT
+Usage: $ME [-h]
+       $ME [-c <commit>] [-v] [-m <val>] [-j <val>] [-t <val>] [-i <image-name>] [-d <path>]
+Options:
+	-h
+		Display this help and exit.
+	-c <commit>
+		git checkout <commit> before anything else
+	-v
+		Show bitbake output, don't redirect it to a log.
+	-m <machine>
+		Value for MACHINE. Default is qemux86.
+	-j <val>
+		Value for PARALLEL_MAKE. Default is 8. 
+	-t <val>
+		Value for BB_NUMBER_THREADS. Default is 8.
+        -i <image-name>
+                Instead of timing agains core-image-sato, use <image-name>
+        -d <path>
+                Use <path> as DL_DIR
+		
+Note: current working directory must be inside a poky git clone.
+ 
+EOT
+}
+
+
+if clonedir=$(git rev-parse --show-toplevel); then
+        cd $clonedir
+else
+        echo "The current working dir doesn't seem to be a poky git clone. Please cd there before running $ME"
+        exit 1
+fi
+
+IMAGE="core-image-sato"
+verbose=0
+dldir=
+commit=
+pmake=
+while getopts "hvc:m:j:t:i:d:" opt; do
+	case $opt in
+		h)	usage
+			exit 0
+			;;
+		v)	verbose=1
+			;;
+		c)	commit=$OPTARG
+			;;
+		m)      export MACHINE=$OPTARG
+			;;
+		j)	pmake=$OPTARG
+			;;
+		t)	export BB_NUMBER_THREADS=$OPTARG
+			;;
+                i)      IMAGE=$OPTARG
+                        ;;
+                d)      dldir=$OPTARG
+                        ;;
+		*)	usage
+			exit 1
+			;;			
+	esac
+done
+
+
+#drop cached credentials and test for sudo access without a password
+sudo -k -n ls > /dev/null 2>&1
+reqpass=$?
+if [ $reqpass -ne 0 ]; then
+    echo "The script requires sudo access to drop caches between builds (echo 3 > /proc/sys/vm/drop_caches)"
+    read -s -p "Please enter your sudo password: " pass
+    echo
+fi
+
+if [ -n "$commit" ]; then
+            echo "git checkout $commit"
+            git checkout $commit || exit 1
+            git pull || exit 1
+fi
+
+rev=$(git rev-parse --short HEAD)  || exit 1
+OUTDIR="$clonedir/build-perf-test/results-$rev-`date "+%Y%m%d%H%M%S"`"
+BUILDDIR="$OUTDIR/build"
+resultsfile="$OUTDIR/results.log"
+bboutput="$OUTDIR/bitbake.log"
+myoutput="$OUTDIR/output.log"
+
+mkdir -p $OUTDIR || exit 1
+                                
+log () {
+    local msg="$1"
+    echo "`date`: $msg" | tee -a $myoutput
+}
+
+
+#
+# Config stuff
+#
+
+log "Git revision is $rev"
+
+source ./oe-init-build-env $OUTDIR/build >/dev/null
+cd $OUTDIR/build
+
+[ -n "$MACHINE" ] || export MACHINE="qemux86"
+[ -n "$BB_NUMBER_THREADS" ] || export BB_NUMBER_THREADS="8"
+
+if [ -n "$pmake" ]; then
+        export PARALLEL_MAKE="-j $pmake"
+else
+        export PARALLEL_MAKE="-j 8"
+fi
+
+if [ -n "$dldir" ]; then
+    echo "DL_DIR = \"$dldir\"" >> conf/local.conf
+else
+    echo "DL_DIR = \"$clonedir/build-perf-test/downloads\"" >> conf/local.conf
+fi
+
+#
+# Functions
+#
+
+bbtime () {
+    log "Running and timing bitbake $1"
+    if [ $verbose -eq 0 ]; then 
+        /usr/bin/time -v -o $resultsfile bitbake "$1" >> $bboutput
+    else
+        /usr/bin/time -v -o $resultsfile bitbake "$1" 
+    fi
+    ret=$?
+    if [ $ret -eq 0 ]; then
+        log "Finished bitbake $1"
+    else
+        log "Exit status was non-zero. Exit..."
+        exit $ret 
+    fi
+    
+    log "Time: `grep wall $resultsfile`"
+    #time by default overwrites the output file and we  want to keep the results
+    #it has an append option but I don't want to clobber the results in the same file
+    i=`ls $OUTDIR/results.log* |wc -l`
+    mv $resultsfile "${resultsfile}.${i}"
+    log "More stats can be found in ${resultsfile}.${i}"    
+}
+
+#we don't time bitbake here
+bbnotime () {
+    log "Running bitbake $1"
+    if [ $verbose -eq 0 ]; then
+        bitbake "$1" >> $bboutput
+    else
+        bitbake "$1" 
+    fi
+    ret=$?
+    if [ $ret -eq 0 ]; then
+        log "Finished bitbake $1"
+    else
+        log "Exit status was non-zero. Exit.."
+        exit $?
+    fi
+
+}
+
+do_rmtmp() {
+    log "Removing tmp"
+    rm -rf bitbake.lock pseudone tmp conf/sanity_info
+}
+do_rmsstate () {
+    log "Removing sstate-cache"
+    rm -rf sstate-cache
+}
+do_sync () {
+    log "Syncing and dropping caches"
+    sync; sync
+    if [ $reqpass -eq 0 ]; then
+        sudo sh -c "echo 3 > /proc/sys/vm/drop_caches"
+    else
+        echo "$pass" | sudo -S sh -c "echo 3 > /proc/sys/vm/drop_caches"
+        echo
+    fi
+    sleep 3
+}
+
+####
+
+#
+# Test 1
+# Measure: Wall clock of "bitbake core-image-sato" and size of tmp/dir (w/o rm_work and w/ rm_work)
+# Pre: Downloaded sources, no sstate
+# Steps:
+#     Part1:
+#        - fetchall 
+#        - clean build dir
+#        - time bitbake core-image-sato
+#        - collect data
+#     Part2:
+#        - bitbake virtual/kernel -c
+#        - time bitbake virtual/kernel
+#     Part3:
+#        - add INHERIT to local.conf
+#        - clean build dir
+#        - build
+#        - report size, remove INHERIT
+
+test1_p1 () {
+log "Running Test 1, part 1/3: Measure wall clock of bitbake $IMAGE and size of tmp/ dir"
+bbnotime "$IMAGE -c fetchall"
+do_rmtmp
+do_rmsstate
+do_sync
+bbtime "$IMAGE"
+log "Size of tmp dir is: `du -hc tmp | grep total`"
+log "Buildstats are saved in $OUTDIR/buildstats-test1"
+mv tmp/buildstats $OUTDIR/buildstats-test1
+}
+
+
+test1_p2 () {
+log "Running Test 1, part 2/3: bitbake virtual/kernel -c clean && cleansstate and time bitbake virtual/kernel"
+bbnotime "virtual/kernel -c clean"
+bbnotime "virtual/kernel -c cleansstate"
+do_sync
+bbtime "virtual/kernel"
+}
+
+test1_p3 () {
+log "Running Test 1, part 3/3: Build $IMAGE w/o sstate and report size of tmp/dir with rm_work enabled"
+echo "INHERIT += \"rm_work\"" >> conf/local.conf
+do_rmtmp
+do_rmsstate
+do_sync
+bbtime "$IMAGE"
+log "Size of tmp dir is: `du -hc tmp | grep total`"
+sed -i 's/INHERIT += \"rm_work\"//' conf/local.conf
+}
+
+
+#
+# Test 2
+# Measure: Wall clock of "bitbake core-image-sato" and size of tmp/dir
+# Pre: populated sstate cache
+
+test2 () {
+#assuming test 1 has run
+log "Running Test 2: Measure wall clock of bitbake $IMAGE -c rootfs with sstate"
+do_rmtmp
+do_sync
+bbtime "$IMAGE -c rootfs"
+}
+
+
+# RUN!
+
+test1_p1
+test1_p2
+test1_p3
+test2
+
+log "All done."
+
+
+
+
+
+
+
-- 
1.8.1.4

[PATCH 2/4] scripts/contrib/build-perf-test.sh: add a global results file

[Stefan Stanacar]

Append results from each run to a single file in order to keep a history.
Also do some cosmetic changes and fix some whitespace.

Signed-off-by: Stefan Stanacar <stefanx.stanacar@intel.com>
---
 scripts/contrib/build-perf-test.sh | 43 ++++++++++++++++++++++++--------------
 1 file changed, 27 insertions(+), 16 deletions(-)

diff --git a/scripts/contrib/build-perf-test.sh b/scripts/contrib/build-perf-test.sh
index 2d70cfa..0f7a3a9 100755
--- a/scripts/contrib/build-perf-test.sh
+++ b/scripts/contrib/build-perf-test.sh
@@ -108,8 +108,9 @@ fi
 
 if [ -n "$commit" ]; then
             echo "git checkout $commit"
+            git pull > /dev/null 2>&1
             git checkout $commit || exit 1
-            git pull || exit 1
+            git pull > /dev/null 2>&1
 fi
 
 rev=$(git rev-parse --short HEAD)  || exit 1
@@ -118,6 +119,7 @@ BUILDDIR="$OUTDIR/build"
 resultsfile="$OUTDIR/results.log"
 bboutput="$OUTDIR/bitbake.log"
 myoutput="$OUTDIR/output.log"
+globalres="$clonedir/build-perf-test/globalres.log"
 
 mkdir -p $OUTDIR || exit 1
                                 
@@ -131,9 +133,10 @@ log () {
 # Config stuff
 #
 
+rev=$(git rev-parse HEAD) || exit 1
 log "Git revision is $rev"
 
-source ./oe-init-build-env $OUTDIR/build >/dev/null
+source ./oe-init-build-env $OUTDIR/build >/dev/null || exit 1
 cd $OUTDIR/build
 
 [ -n "$MACHINE" ] || export MACHINE="qemux86"
@@ -155,8 +158,12 @@ fi
 # Functions
 #
 
+declare -a TIMES
+time_count=0
+
 bbtime () {
-    log "Running and timing bitbake $1"
+    log "Timing: bitbake $1"
+
     if [ $verbose -eq 0 ]; then 
         /usr/bin/time -v -o $resultsfile bitbake "$1" >> $bboutput
     else
@@ -164,13 +171,14 @@ bbtime () {
     fi
     ret=$?
     if [ $ret -eq 0 ]; then
-        log "Finished bitbake $1"
+        t=`grep wall $resultsfile | sed 's/.*m:ss): //'`
+        log "Time: $t"
+        TIMES[(( time_count++ ))]="$t"
     else
         log "Exit status was non-zero. Exit..."
         exit $ret 
     fi
     
-    log "Time: `grep wall $resultsfile`"
     #time by default overwrites the output file and we  want to keep the results
     #it has an append option but I don't want to clobber the results in the same file
     i=`ls $OUTDIR/results.log* |wc -l`
@@ -180,7 +188,7 @@ bbtime () {
 
 #we don't time bitbake here
 bbnotime () {
-    log "Running bitbake $1"
+    log "Running: bitbake $1"
     if [ $verbose -eq 0 ]; then
         bitbake "$1" >> $bboutput
     else
@@ -198,7 +206,7 @@ bbnotime () {
 
 do_rmtmp() {
     log "Removing tmp"
-    rm -rf bitbake.lock pseudone tmp conf/sanity_info
+    rm -rf bitbake.lock pseudodone tmp conf/sanity_info
 }
 do_rmsstate () {
     log "Removing sstate-cache"
@@ -244,7 +252,7 @@ do_rmtmp
 do_rmsstate
 do_sync
 bbtime "$IMAGE"
-log "Size of tmp dir is: `du -hc tmp | grep total`"
+log "Size of tmp dir is: `du -sh tmp | sed 's/tmp//'`"
 log "Buildstats are saved in $OUTDIR/buildstats-test1"
 mv tmp/buildstats $OUTDIR/buildstats-test1
 }
@@ -265,8 +273,10 @@ do_rmtmp
 do_rmsstate
 do_sync
 bbtime "$IMAGE"
-log "Size of tmp dir is: `du -hc tmp | grep total`"
 sed -i 's/INHERIT += \"rm_work\"//' conf/local.conf
+log "Size of tmp dir is: `du -sh tmp | sed 's/tmp//'`"
+log "Buildstats are saved in $OUTDIR/buildstats-test13"
+mv tmp/buildstats $OUTDIR/buildstats-test13
 }
 
 
@@ -291,11 +301,12 @@ test1_p2
 test1_p3
 test2
 
-log "All done."
-
-
-
-
-
-
+log "All done"
 
+# if we got til here write to global results
+echo "$rev" >> $globalres
+for i in "${TIMES[@]}"; do
+    echo -n "$i," >> $globalres
+done
+echo >> $globalres
+sed -i '$ s/,$//' $globalres
-- 
1.8.1.4

[PATCH 3/4] scripts/contrib/build-perf-test.sh: add option to allow cherry-picking of fix revisions

[Stefan Stanacar]

From: Richard Purdie <richard@linuxfoundation.org>

Adds a -p option to allow cherry-picking of fix revisions.
Removes the final build/sstate directories to stop running out of space.
Runs subsequent tasks even if one test fails.

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Signed-off-by: Stefan Stanacar <stefanx.stanacar@intel.com>
---
 scripts/contrib/build-perf-test.sh | 84 ++++++++++++++++++++++----------------
 1 file changed, 49 insertions(+), 35 deletions(-)

diff --git a/scripts/contrib/build-perf-test.sh b/scripts/contrib/build-perf-test.sh
index 0f7a3a9..103475d 100755
--- a/scripts/contrib/build-perf-test.sh
+++ b/scripts/contrib/build-perf-test.sh
@@ -36,23 +36,25 @@ cat << EOT
 Usage: $ME [-h]
        $ME [-c <commit>] [-v] [-m <val>] [-j <val>] [-t <val>] [-i <image-name>] [-d <path>]
 Options:
-	-h
-		Display this help and exit.
-	-c <commit>
-		git checkout <commit> before anything else
-	-v
-		Show bitbake output, don't redirect it to a log.
-	-m <machine>
-		Value for MACHINE. Default is qemux86.
-	-j <val>
-		Value for PARALLEL_MAKE. Default is 8. 
-	-t <val>
-		Value for BB_NUMBER_THREADS. Default is 8.
+        -h
+                Display this help and exit.
+        -c <commit>
+                git checkout <commit> before anything else
+        -v
+                Show bitbake output, don't redirect it to a log.
+        -m <machine>
+                Value for MACHINE. Default is qemux86.
+        -j <val>
+                Value for PARALLEL_MAKE. Default is 8. 
+        -t <val>
+                Value for BB_NUMBER_THREADS. Default is 8.
         -i <image-name>
                 Instead of timing agains core-image-sato, use <image-name>
         -d <path>
                 Use <path> as DL_DIR
-		
+        -p <githash>
+                Cherry pick githash onto the commit
+                
 Note: current working directory must be inside a poky git clone.
  
 EOT
@@ -71,29 +73,32 @@ verbose=0
 dldir=
 commit=
 pmake=
-while getopts "hvc:m:j:t:i:d:" opt; do
-	case $opt in
-		h)	usage
-			exit 0
-			;;
-		v)	verbose=1
-			;;
-		c)	commit=$OPTARG
-			;;
-		m)      export MACHINE=$OPTARG
-			;;
-		j)	pmake=$OPTARG
-			;;
-		t)	export BB_NUMBER_THREADS=$OPTARG
-			;;
+cherrypicks=
+while getopts "hvc:m:j:t:i:d:p:" opt; do
+        case $opt in
+                h)      usage
+                        exit 0
+                        ;;
+                v)      verbose=1
+                        ;;
+                c)      commit=$OPTARG
+                        ;;
+                m)      export MACHINE=$OPTARG
+                        ;;
+                j)      pmake=$OPTARG
+                        ;;
+                t)      export BB_NUMBER_THREADS=$OPTARG
+                        ;;
                 i)      IMAGE=$OPTARG
                         ;;
                 d)      dldir=$OPTARG
                         ;;
-		*)	usage
-			exit 1
-			;;			
-	esac
+                p)      cherrypicks="$cherrypicks $OPTARG"
+                        ;;
+                *)      usage
+                        exit 1
+                        ;;                      
+        esac
 done
 
 
@@ -113,6 +118,12 @@ if [ -n "$commit" ]; then
             git pull > /dev/null 2>&1
 fi
 
+if [ -n "$cherrypicks" ]; then
+    for c in $cherrypicks; do
+        git cherry-pick $c
+    done
+fi
+
 rev=$(git rev-parse --short HEAD)  || exit 1
 OUTDIR="$clonedir/build-perf-test/results-$rev-`date "+%Y%m%d%H%M%S"`"
 BUILDDIR="$OUTDIR/build"
@@ -176,7 +187,7 @@ bbtime () {
         TIMES[(( time_count++ ))]="$t"
     else
         log "Exit status was non-zero. Exit..."
-        exit $ret 
+        #exit $ret 
     fi
     
     #time by default overwrites the output file and we  want to keep the results
@@ -269,8 +280,8 @@ bbtime "virtual/kernel"
 test1_p3 () {
 log "Running Test 1, part 3/3: Build $IMAGE w/o sstate and report size of tmp/dir with rm_work enabled"
 echo "INHERIT += \"rm_work\"" >> conf/local.conf
-do_rmtmp
-do_rmsstate
+#do_rmtmp
+#do_rmsstate
 do_sync
 bbtime "$IMAGE"
 sed -i 's/INHERIT += \"rm_work\"//' conf/local.conf
@@ -303,6 +314,9 @@ test2
 
 log "All done"
 
+do_rmtmp
+do_rmsstate
+
 # if we got til here write to global results
 echo "$rev" >> $globalres
 for i in "${TIMES[@]}"; do
-- 
1.8.1.4

[PATCH 4/4] scripts/contrib/build-perf-test.sh: add timings for bitbake -p

[Stefan Stanacar]

Add another test to time bitbake -p with and without cache/ or tmp/cache.

Signed-off-by: Stefan Stanacar <stefanx.stanacar@intel.com>
---
 scripts/contrib/build-perf-test.sh | 62 ++++++++++++++++++++++++++------------
 1 file changed, 42 insertions(+), 20 deletions(-)

diff --git a/scripts/contrib/build-perf-test.sh b/scripts/contrib/build-perf-test.sh
index 103475d..44a902c 100755
--- a/scripts/contrib/build-perf-test.sh
+++ b/scripts/contrib/build-perf-test.sh
@@ -49,7 +49,7 @@ Options:
         -t <val>
                 Value for BB_NUMBER_THREADS. Default is 8.
         -i <image-name>
-                Instead of timing agains core-image-sato, use <image-name>
+                Instead of timing against core-image-sato, use <image-name>
         -d <path>
                 Use <path> as DL_DIR
         -p <githash>
@@ -173,7 +173,7 @@ declare -a TIMES
 time_count=0
 
 bbtime () {
-    log "Timing: bitbake $1"
+    log "   Timing: bitbake $1"
 
     if [ $verbose -eq 0 ]; then 
         /usr/bin/time -v -o $resultsfile bitbake "$1" >> $bboutput
@@ -183,11 +183,11 @@ bbtime () {
     ret=$?
     if [ $ret -eq 0 ]; then
         t=`grep wall $resultsfile | sed 's/.*m:ss): //'`
-        log "Time: $t"
+        log "   TIME: $t"
         TIMES[(( time_count++ ))]="$t"
     else
-        log "Exit status was non-zero. Exit..."
-        #exit $ret 
+        log "ERROR: exit status was non-zero, will report time as 0."
+        TIMES[(( time_count++ ))]="0"
     fi
     
     #time by default overwrites the output file and we  want to keep the results
@@ -199,7 +199,7 @@ bbtime () {
 
 #we don't time bitbake here
 bbnotime () {
-    log "Running: bitbake $1"
+    log "   Running: bitbake $1"
     if [ $verbose -eq 0 ]; then
         bitbake "$1" >> $bboutput
     else
@@ -207,24 +207,24 @@ bbnotime () {
     fi
     ret=$?
     if [ $ret -eq 0 ]; then
-        log "Finished bitbake $1"
+        log "   Finished bitbake $1"
     else
-        log "Exit status was non-zero. Exit.."
+        log "ERROR: exit status was non-zero. Exit.."
         exit $?
     fi
 
 }
 
 do_rmtmp() {
-    log "Removing tmp"
-    rm -rf bitbake.lock pseudodone tmp conf/sanity_info
+    log "   Removing tmp"
+    rm -rf bitbake.lock pseudodone conf/sanity_info cache tmp
 }
 do_rmsstate () {
-    log "Removing sstate-cache"
+    log "   Removing sstate-cache"
     rm -rf sstate-cache
 }
 do_sync () {
-    log "Syncing and dropping caches"
+    log "   Syncing and dropping caches"
     sync; sync
     if [ $reqpass -eq 0 ]; then
         sudo sh -c "echo 3 > /proc/sys/vm/drop_caches"
@@ -248,7 +248,7 @@ do_sync () {
 #        - time bitbake core-image-sato
 #        - collect data
 #     Part2:
-#        - bitbake virtual/kernel -c
+#        - bitbake virtual/kernel -c cleansstate
 #        - time bitbake virtual/kernel
 #     Part3:
 #        - add INHERIT to local.conf
@@ -263,15 +263,14 @@ do_rmtmp
 do_rmsstate
 do_sync
 bbtime "$IMAGE"
-log "Size of tmp dir is: `du -sh tmp | sed 's/tmp//'`"
+log "SIZE of tmp dir is: `du -sh tmp | sed 's/tmp//'`"
 log "Buildstats are saved in $OUTDIR/buildstats-test1"
 mv tmp/buildstats $OUTDIR/buildstats-test1
 }
 
 
 test1_p2 () {
-log "Running Test 1, part 2/3: bitbake virtual/kernel -c clean && cleansstate and time bitbake virtual/kernel"
-bbnotime "virtual/kernel -c clean"
+log "Running Test 1, part 2/3: bitbake virtual/kernel -c cleansstate and time bitbake virtual/kernel"
 bbnotime "virtual/kernel -c cleansstate"
 do_sync
 bbtime "virtual/kernel"
@@ -280,12 +279,12 @@ bbtime "virtual/kernel"
 test1_p3 () {
 log "Running Test 1, part 3/3: Build $IMAGE w/o sstate and report size of tmp/dir with rm_work enabled"
 echo "INHERIT += \"rm_work\"" >> conf/local.conf
-#do_rmtmp
-#do_rmsstate
+do_rmtmp
+do_rmsstate
 do_sync
 bbtime "$IMAGE"
 sed -i 's/INHERIT += \"rm_work\"//' conf/local.conf
-log "Size of tmp dir is: `du -sh tmp | sed 's/tmp//'`"
+log "SIZE of tmp dir is: `du -sh tmp | sed 's/tmp//'`"
 log "Buildstats are saved in $OUTDIR/buildstats-test13"
 mv tmp/buildstats $OUTDIR/buildstats-test13
 }
@@ -305,14 +304,37 @@ bbtime "$IMAGE -c rootfs"
 }
 
 
+# Test 3
+# parsing time metrics
+#
+#  Start with
+#   i) "rm -rf tmp/cache; time bitbake -p"
+#  ii) "rm -rf tmp/cache/default-eglibc/; time bitbake -p"
+# iii) "time bitbake -p"
+
+
+test3 () {
+log "Running Test 3: Parsing time metrics (bitbake -p)"
+log "   Removing tmp/cache && cache"
+rm -rf tmp/cache cache
+bbtime "-p"
+log "   Removing tmp/cache/default-eglibc/"
+rm -rf tmp/cache/default-eglibc/
+bbtime "-p"
+bbtime "-p"
+}
+
+
+
 # RUN!
 
 test1_p1
 test1_p2
 test1_p3
 test2
+test3
 
-log "All done"
+log "All done, cleaning up..."
 
 do_rmtmp
 do_rmsstate
-- 
1.8.1.4