[PATCH 00/12] oe-build-perf-test: new format for test output data

[PATCH 00/12] oe-build-perf-test: new format for test output data

[Markus Lehtonen]

This patchset changes the structure and format of the test output data. The
goal is to make the test result format more consolidated and easier to consume.
The major change is that the test results are stored in JSON format, in
addition to the (optional) csv-formatted "globalres file". Also, buildstats are
converted into JSON.

This patchset is based on top of the earlier "test inter-dependency removal"
patchset for oe-build-perf-test.

[YOCTO #9625]

The following changes since commit 74a62a0a9e4758de4bd2d891f9a133f028e86913:

  oe-build-perf-test: update globalres and git even if tests failed (2016-08-26 10:11:38 +0300)

are available in the git repository at:

  git://git.openembedded.org/openembedded-core-contrib marquiz/buildperf/new-result-fmt
  http://git.openembedded.org/openembedded-core-contrib/log/?h=marquiz/buildperf/new-result-fmt


Markus Lehtonen (12):
  oeqa.buildperf: add 'product' to test result data
  oeqa.buildperf: enable json-formatted results
  oe-build-perf-test: rename log file and implement --log-file
  oeqa.buildperf: strip date from buildstats directory path
  oeqa.buildperf: separate output dir for each test
  oeqa.buildperf: rename buildstats directories
  oeqa.buildperf: don't use Gnu time
  oeqa.buildperf: measure io stat
  oeqa.buildperf: convert buildstats into json format
  oeqa.buildperf: show skipped tests in results, too
  oeqa.buildperf: include buildstats file name in results.json
  oeqa.buildperf: include commands log file name in results.json

 meta/lib/oeqa/buildperf/base.py       | 228 +++++++++++++++++++++++++++-------
 meta/lib/oeqa/buildperf/test_basic.py |   7 +-
 scripts/oe-build-perf-test            |   5 +-
 3 files changed, 190 insertions(+), 50 deletions(-)

-- 
2.6.6

[PATCH 01/12] oeqa.buildperf: add 'product' to test result data

[Markus Lehtonen]

This defaults to 'oe-core' but can be defined using the
OE_BUILDPERF_PRODUCT environment variable.

Signed-off-by: Markus Lehtonen <markus.lehtonen@linux.intel.com>
---
 meta/lib/oeqa/buildperf/base.py | 1 +
 1 file changed, 1 insertion(+)

diff --git a/meta/lib/oeqa/buildperf/base.py b/meta/lib/oeqa/buildperf/base.py
index dbc534e..ed8ff4a 100644
--- a/meta/lib/oeqa/buildperf/base.py
+++ b/meta/lib/oeqa/buildperf/base.py
@@ -97,6 +97,7 @@ class BuildPerfTestResult(unittest.TextTestResult):
         self.git_commit, self.git_commit_count, self.git_branch = \
                 self.get_git_revision()
         self.hostname = socket.gethostname()
+        self.product = os.getenv('OE_BUILDPERFTEST_PRODUCT', 'oe-core')
         self.start_time = self.elapsed_time = None
         self.successes = []
         log.info("Using Git branch:commit %s:%s (%s)", self.git_branch,
-- 
2.6.6

[PATCH 02/12] oeqa.buildperf: enable json-formatted results

[Markus Lehtonen]

Automatically create a json.formatted file (results.json) in the results
directory that contains results from all tests.

Signed-off-by: Markus Lehtonen <markus.lehtonen@linux.intel.com>
---
 meta/lib/oeqa/buildperf/base.py | 40 ++++++++++++++++++++++++++++++++++++++++
 1 file changed, 40 insertions(+)

diff --git a/meta/lib/oeqa/buildperf/base.py b/meta/lib/oeqa/buildperf/base.py
index ed8ff4a..eed0266 100644
--- a/meta/lib/oeqa/buildperf/base.py
+++ b/meta/lib/oeqa/buildperf/base.py
@@ -11,6 +11,7 @@
 #
 """Build performance test base classes and functionality"""
 import glob
+import json
 import logging
 import os
 import re
@@ -80,6 +81,20 @@ def time_cmd(cmd, **kwargs):
     return ret, timedata
 
 
+class ResultsJsonEncoder(json.JSONEncoder):
+    """Extended encoder for build perf test results"""
+    unix_epoch = datetime.utcfromtimestamp(0)
+
+    def default(self, obj):
+        """Encoder for our types"""
+        if isinstance(obj, datetime):
+            # NOTE: we assume that all timestamps are in UTC time
+            return (obj - self.unix_epoch).total_seconds()
+        if isinstance(obj, timedelta):
+            return obj.total_seconds()
+        return json.JSONEncoder.default(self, obj)
+
+
 class BuildPerfTestResult(unittest.TextTestResult):
     """Runner class for executing the individual tests"""
     # List of test cases to run
@@ -143,6 +158,7 @@ class BuildPerfTestResult(unittest.TextTestResult):
     def stopTestRun(self):
         """Pre-run hook"""
         self.elapsed_time = datetime.utcnow() - self.start_time
+        self.write_results_json()
 
     def all_results(self):
         result_map = {'SUCCESS': self.successes,
@@ -190,6 +206,30 @@ class BuildPerfTestResult(unittest.TextTestResult):
                                              git_tag_rev))
             fobj.write(','.join(values) + '\n')
 
+    def write_results_json(self):
+        """Write test results into a json-formatted file"""
+        results = {'tester_host': self.hostname,
+                   'git_branch': self.git_branch,
+                   'git_commit': self.git_commit,
+                   'git_commit_count': self.git_commit_count,
+                   'product': self.product,
+                   'start_time': self.start_time,
+                   'elapsed_time': self.elapsed_time}
+
+        tests = {}
+        for status, (test, reason) in self.all_results():
+            tests[test.name] = {'name': test.name,
+                                'description': test.shortDescription(),
+                                'status': status,
+                                'start_time': test.start_time,
+                                'elapsed_time': test.elapsed_time,
+                                'measurements': test.measurements}
+        results['tests'] = tests
+
+        with open(os.path.join(self.out_dir, 'results.json'), 'w') as fobj:
+            json.dump(results, fobj, indent=4, sort_keys=True,
+                      cls=ResultsJsonEncoder)
+
 
     def git_commit_results(self, repo_path, branch=None, tag=None):
         """Commit results into a Git repository"""
-- 
2.6.6

[PATCH 03/12] oe-build-perf-test: rename log file and implement --log-file

[Markus Lehtonen]

Rename the (main) log file of the oe-build-perf-test script from
'output.log' to 'oe-build-perf-test.log'. Also, add a new command line
option --log-file which makes it possible to use an alternative log file
name/path, if needed.  Note that the file name/path is relative to the
output directory.

Signed-off-by: Markus Lehtonen <markus.lehtonen@linux.intel.com>
---
 scripts/oe-build-perf-test | 5 ++++-
 1 file changed, 4 insertions(+), 1 deletion(-)

diff --git a/scripts/oe-build-perf-test b/scripts/oe-build-perf-test
index 3dab070..8d7fdf2 100755
--- a/scripts/oe-build-perf-test
+++ b/scripts/oe-build-perf-test
@@ -131,6 +131,9 @@ def parse_args(argv):
     parser.add_argument('-o', '--out-dir', default='results-{date}',
                         type=os.path.abspath,
                         help="Output directory for test results")
+    parser.add_argument('--log-file', type=os.path.abspath,
+                        default='{out_dir}/oe-build-perf-test.log',
+                        help="Log file of this script")
     parser.add_argument('--run-tests', nargs='+', metavar='TEST',
                         help="List of tests to run")
     parser.add_argument('--commit-results', metavar='GIT_DIR',
@@ -152,7 +155,7 @@ def main(argv=None):
 
     # Set-up log file
     out_dir = args.out_dir.format(date=datetime.now().strftime('%Y%m%d%H%M%S'))
-    setup_file_logging(os.path.join(out_dir, 'output.log'))
+    setup_file_logging(args.log_file.format(out_dir=out_dir))
 
     if args.debug:
         log.setLevel(logging.DEBUG)
-- 
2.6.6

[PATCH 04/12] oeqa.buildperf: strip date from buildstats directory path

[Markus Lehtonen]

Archive buildstats in a directory like 'buildstats' instead of something
like 'buildstats/20160513120000'.

Signed-off-by: Markus Lehtonen <markus.lehtonen@linux.intel.com>
---
 meta/lib/oeqa/buildperf/base.py | 6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)

diff --git a/meta/lib/oeqa/buildperf/base.py b/meta/lib/oeqa/buildperf/base.py
index eed0266..4918e79 100644
--- a/meta/lib/oeqa/buildperf/base.py
+++ b/meta/lib/oeqa/buildperf/base.py
@@ -395,7 +395,11 @@ class BuildPerfTestCase(unittest.TestCase):
 
     def save_buildstats(self):
         """Save buildstats"""
-        shutil.move(self.bb_vars['BUILDSTATS_BASE'],
+        bs_dirs = os.listdir(self.bb_vars['BUILDSTATS_BASE'])
+        if len(bs_dirs) > 1:
+            log.warning("Multiple buildstats found for test %s, only "
+                        "archiving the last one", self.name)
+        shutil.move(os.path.join(self.bb_vars['BUILDSTATS_BASE'], bs_dirs[-1]),
                     os.path.join(self.out_dir, 'buildstats-' + self.name))
 
     def rm_tmp(self):
-- 
2.6.6

[PATCH 05/12] oeqa.buildperf: separate output dir for each test

[Markus Lehtonen]

Store the output data of each test in an individual subdirectory instead
of storing everything in the root output directory.

Signed-off-by: Markus Lehtonen <markus.lehtonen@linux.intel.com>
---
 meta/lib/oeqa/buildperf/base.py | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/meta/lib/oeqa/buildperf/base.py b/meta/lib/oeqa/buildperf/base.py
index 4918e79..64c1a44 100644
--- a/meta/lib/oeqa/buildperf/base.py
+++ b/meta/lib/oeqa/buildperf/base.py
@@ -146,7 +146,8 @@ class BuildPerfTestResult(unittest.TextTestResult):
 
     def startTest(self, test):
         """Pre-test hook"""
-        test.out_dir = self.out_dir
+        test.out_dir = os.path.join(self.out_dir, test.name)
+        os.mkdir(test.out_dir)
         log.info("Executing test %s: %s", test.name, test.shortDescription())
         self.stream.write(datetime.now().strftime("[%Y-%m-%d %H:%M:%S] "))
         super(BuildPerfTestResult, self).startTest(test)
-- 
2.6.6

[PATCH 06/12] oeqa.buildperf: rename buildstats directories

[Markus Lehtonen]

Change directory name from 'buildstats-<test_name>' to just
'buildstats'. However, this patch adds the possibility to label
buildstats directory name with a postfix which makes it possible to save
multiple buildstats per test, for example.

Signed-off-by: Markus Lehtonen <markus.lehtonen@linux.intel.com>
---
 meta/lib/oeqa/buildperf/base.py | 5 +++--
 1 file changed, 3 insertions(+), 2 deletions(-)

diff --git a/meta/lib/oeqa/buildperf/base.py b/meta/lib/oeqa/buildperf/base.py
index 64c1a44..de22850 100644
--- a/meta/lib/oeqa/buildperf/base.py
+++ b/meta/lib/oeqa/buildperf/base.py
@@ -394,14 +394,15 @@ class BuildPerfTestCase(unittest.TestCase):
         # Append to 'sizes' array for globalres log
         self.sizes.append(str(size))
 
-    def save_buildstats(self):
+    def save_buildstats(self, label=None):
         """Save buildstats"""
         bs_dirs = os.listdir(self.bb_vars['BUILDSTATS_BASE'])
         if len(bs_dirs) > 1:
             log.warning("Multiple buildstats found for test %s, only "
                         "archiving the last one", self.name)
+        postfix = '-' + label if label else ''
         shutil.move(os.path.join(self.bb_vars['BUILDSTATS_BASE'], bs_dirs[-1]),
-                    os.path.join(self.out_dir, 'buildstats-' + self.name))
+                    os.path.join(self.out_dir, 'buildstats' + postfix))
 
     def rm_tmp(self):
         """Cleanup temporary/intermediate files and directories"""
-- 
2.6.6

[PATCH 07/12] oeqa.buildperf: don't use Gnu time

[Markus Lehtonen]

Use Python standard library functionality instead of the time utility
for measuring elapsed (wall clock) time of commands. The time.* log
files are also ditched. However, the same detailed resource usage data,
previously found in time.* logs is now provided in results.json file.
This data is collected through the resource module of Python.

Signed-off-by: Markus Lehtonen <markus.lehtonen@linux.intel.com>
---
 meta/lib/oeqa/buildperf/base.py | 72 ++++++++++++++++++++++-------------------
 1 file changed, 39 insertions(+), 33 deletions(-)

diff --git a/meta/lib/oeqa/buildperf/base.py b/meta/lib/oeqa/buildperf/base.py
index de22850..5987bfb 100644
--- a/meta/lib/oeqa/buildperf/base.py
+++ b/meta/lib/oeqa/buildperf/base.py
@@ -15,14 +15,16 @@ import json
 import logging
 import os
 import re
+import resource
 import shutil
 import socket
-import tempfile
 import time
 import traceback
 import unittest
 from datetime import datetime, timedelta
 from functools import partial
+from multiprocessing import Process
+from multiprocessing import SimpleQueue
 
 import oe.path
 from oeqa.utils.commands import CommandError, runCmd, get_bb_vars
@@ -69,16 +71,9 @@ class KernelDropCaches(object):
         runCmd2(cmd, data=input_data)
 
 
-def time_cmd(cmd, **kwargs):
-    """TIme a command"""
-    with tempfile.NamedTemporaryFile(mode='w+') as tmpf:
-        timecmd = ['/usr/bin/time', '-v', '-o', tmpf.name]
-        if isinstance(cmd, str):
-            timecmd = ' '.join(timecmd) + ' '
-        timecmd += cmd
-        ret = runCmd2(timecmd, **kwargs)
-        timedata = tmpf.file.read()
-    return ret, timedata
+def str_to_fn(string):
+    """Convert string to a sanitized filename"""
+    return re.sub(r'(\W+)', '-', string, flags=re.LOCALE)
 
 
 class ResultsJsonEncoder(json.JSONEncoder):
@@ -338,45 +333,56 @@ class BuildPerfTestCase(unittest.TestCase):
 
     def measure_cmd_resources(self, cmd, name, legend):
         """Measure system resource usage of a command"""
-        def str_time_to_timedelta(strtime):
-            """Convert time strig from the time utility to timedelta"""
-            split = strtime.split(':')
-            hours = int(split[0]) if len(split) > 2 else 0
-            mins = int(split[-2])
+        def _worker(data_q, cmd, **kwargs):
+            """Worker process for measuring resources"""
             try:
-                secs, frac = split[-1].split('.')
-            except:
-                secs = split[-1]
-                frac = '0'
-            secs = int(secs)
-            microsecs = int(float('0.' + frac) * pow(10, 6))
-            return timedelta(0, hours*3600 + mins*60 + secs, microsecs)
+                start_time = datetime.now()
+                ret = runCmd2(cmd, **kwargs)
+                etime = datetime.now() - start_time
+                rusage_struct = resource.getrusage(resource.RUSAGE_CHILDREN)
+                rusage = {}
+                # Skip unused fields, (i.e. 'ru_ixrss', 'ru_idrss', 'ru_isrss',
+                # 'ru_nswap', 'ru_msgsnd', 'ru_msgrcv' and 'ru_nsignals')
+                for key in ['ru_utime', 'ru_stime', 'ru_maxrss', 'ru_minflt',
+                            'ru_majflt', 'ru_inblock', 'ru_oublock',
+                            'ru_nvcsw', 'ru_nivcsw']:
+                    rusage[key] = getattr(rusage_struct, key)
+                data_q.put({'ret': ret,
+                            'start_time': start_time,
+                            'elapsed_time': etime,
+                            'rusage': rusage})
+            except Exception as err:
+                data_q.put(err)
 
         cmd_str = cmd if isinstance(cmd, str) else ' '.join(cmd)
         log.info("Timing command: %s", cmd_str)
+        data_q = SimpleQueue()
         cmd_log = os.path.join(self.out_dir, 'commands.log')
         try:
             with open(cmd_log, 'a') as fobj:
-                ret, timedata = time_cmd(cmd, stdout=fobj)
+                proc = Process(target=_worker, args=(data_q, cmd,),
+                               kwargs={'stdout': fobj})
+                proc.start()
+                data = data_q.get()
+                proc.join()
+            if isinstance(data, Exception):
+                raise data
         except CommandError:
             log.error("Command '%s' failed, see %s for more details", cmd_str,
                       cmd_log)
             raise
-        match = re.search(r'.*wall clock.*: (?P<etime>.*)\n', timedata)
-        etime = str_time_to_timedelta(match.group('etime'))
+        etime = data['elapsed_time']
 
         measurement = {'type': self.SYSRES,
                        'name': name,
                        'legend': legend}
-        measurement['values'] = {'elapsed_time': etime}
+        measurement['values'] = {'start_time': data['start_time'],
+                                 'elapsed_time': etime,
+                                 'rusage': data['rusage']}
         self.measurements.append(measurement)
-        e_sec = etime.total_seconds()
-        nlogs = len(glob.glob(self.out_dir + '/results.log*'))
-        results_log = os.path.join(self.out_dir,
-                                   'results.log.{}'.format(nlogs + 1))
-        with open(results_log, 'w') as fobj:
-            fobj.write(timedata)
+
         # Append to 'times' array for globalres log
+        e_sec = etime.total_seconds()
         self.times.append('{:d}:{:02d}:{:.2f}'.format(int(e_sec / 3600),
                                                       int((e_sec % 3600) / 60),
                                                        e_sec % 60))
-- 
2.6.6

[PATCH 08/12] oeqa.buildperf: measure io stat

[Markus Lehtonen]

Add data from /proc/<pid>/io to system resource measurements.

Signed-off-by: Markus Lehtonen <markus.lehtonen@linux.intel.com>
---
 meta/lib/oeqa/buildperf/base.py | 11 +++++++++--
 1 file changed, 9 insertions(+), 2 deletions(-)

diff --git a/meta/lib/oeqa/buildperf/base.py b/meta/lib/oeqa/buildperf/base.py
index 5987bfb..95a0abf 100644
--- a/meta/lib/oeqa/buildperf/base.py
+++ b/meta/lib/oeqa/buildperf/base.py
@@ -340,6 +340,11 @@ class BuildPerfTestCase(unittest.TestCase):
                 ret = runCmd2(cmd, **kwargs)
                 etime = datetime.now() - start_time
                 rusage_struct = resource.getrusage(resource.RUSAGE_CHILDREN)
+                iostat = {}
+                with open('/proc/{}/io'.format(os.getpid())) as fobj:
+                    for line in fobj.readlines():
+                        key, val = line.split(':')
+                        iostat[key] = int(val)
                 rusage = {}
                 # Skip unused fields, (i.e. 'ru_ixrss', 'ru_idrss', 'ru_isrss',
                 # 'ru_nswap', 'ru_msgsnd', 'ru_msgrcv' and 'ru_nsignals')
@@ -350,7 +355,8 @@ class BuildPerfTestCase(unittest.TestCase):
                 data_q.put({'ret': ret,
                             'start_time': start_time,
                             'elapsed_time': etime,
-                            'rusage': rusage})
+                            'rusage': rusage,
+                            'iostat': iostat})
             except Exception as err:
                 data_q.put(err)
 
@@ -378,7 +384,8 @@ class BuildPerfTestCase(unittest.TestCase):
                        'legend': legend}
         measurement['values'] = {'start_time': data['start_time'],
                                  'elapsed_time': etime,
-                                 'rusage': data['rusage']}
+                                 'rusage': data['rusage'],
+                                 'iostat': data['iostat']}
         self.measurements.append(measurement)
 
         # Append to 'times' array for globalres log
-- 
2.6.6

[PATCH 09/12] oeqa.buildperf: convert buildstats into json format

[Markus Lehtonen]

Instead of archiving buildstats in raw text file format convert all
buildstats into one json-formatted file. Some redundant information,
i.e. 'Event:', 'utime:', 'stime:', 'cutime:' and 'cstime:' fields, are
dropped.

Signed-off-by: Markus Lehtonen <markus.lehtonen@linux.intel.com>
---
 meta/lib/oeqa/buildperf/base.py | 69 +++++++++++++++++++++++++++++++++++++++--
 1 file changed, 66 insertions(+), 3 deletions(-)

diff --git a/meta/lib/oeqa/buildperf/base.py b/meta/lib/oeqa/buildperf/base.py
index 95a0abf..c716220 100644
--- a/meta/lib/oeqa/buildperf/base.py
+++ b/meta/lib/oeqa/buildperf/base.py
@@ -409,13 +409,76 @@ class BuildPerfTestCase(unittest.TestCase):
 
     def save_buildstats(self, label=None):
         """Save buildstats"""
+        def split_nevr(nevr):
+            """Split name and version information from recipe "nevr" string"""
+            name, e_v, revision = nevr.rsplit('-', 2)
+            match = re.match(r'^((?P<epoch>[0-9]{1,5})_)?(?P<version>.*)$', e_v)
+            version = match.group('version')
+            epoch = match.group('epoch')
+            return name, epoch, version, revision
+
+        def bs_to_json(filename):
+            """Convert (task) buildstats file into json format"""
+            bs_json = {'iostat': {},
+                       'rusage': {},
+                       'child_rusage': {}}
+            with open(filename) as fobj:
+                for line in fobj.readlines():
+                    key, val = line.split(':', 1)
+                    val = val.strip()
+                    if key == 'Started':
+                        start_time = datetime.utcfromtimestamp(float(val))
+                        bs_json['start_time'] = start_time
+                    elif key == 'Ended':
+                        end_time = datetime.utcfromtimestamp(float(val))
+                    elif key.startswith('IO '):
+                        split = key.split()
+                        bs_json['iostat'][split[1]] = int(val)
+                    elif key.find('rusage') >= 0:
+                        split = key.split()
+                        ru_key = split[-1]
+                        if ru_key in ('ru_stime', 'ru_utime'):
+                            val = float(val)
+                        else:
+                            val = int(val)
+                        ru_type = 'rusage' if split[0] == 'rusage' else \
+                                                          'child_rusage'
+                        bs_json[ru_type][ru_key] = val
+                    elif key == 'Status':
+                        bs_json['status'] = val
+            bs_json['elapsed_time'] = end_time - start_time
+            return bs_json
+
+        log.info('Saving buildstats in JSON format')
         bs_dirs = os.listdir(self.bb_vars['BUILDSTATS_BASE'])
         if len(bs_dirs) > 1:
             log.warning("Multiple buildstats found for test %s, only "
                         "archiving the last one", self.name)
-        postfix = '-' + label if label else ''
-        shutil.move(os.path.join(self.bb_vars['BUILDSTATS_BASE'], bs_dirs[-1]),
-                    os.path.join(self.out_dir, 'buildstats' + postfix))
+        bs_dir = os.path.join(self.bb_vars['BUILDSTATS_BASE'], bs_dirs[-1])
+
+        buildstats = []
+        for fname in os.listdir(bs_dir):
+            recipe_dir = os.path.join(bs_dir, fname)
+            if not os.path.isdir(recipe_dir):
+                continue
+            name, epoch, version, revision = split_nevr(fname)
+            recipe_bs = {'name': name,
+                         'epoch': epoch,
+                         'version': version,
+                         'revision': revision,
+                         'tasks': {}}
+            for task in os.listdir(recipe_dir):
+                recipe_bs['tasks'][task] = bs_to_json(os.path.join(recipe_dir,
+                                                                   task))
+            buildstats.append(recipe_bs)
+
+        # Write buildstats into json file
+        postfix = '.' + label if label else ''
+        postfix += '.json'
+        outfile = os.path.join(self.out_dir, 'buildstats' + postfix)
+        with open(outfile, 'w') as fobj:
+            json.dump(buildstats, fobj, indent=4, sort_keys=True,
+                      cls=ResultsJsonEncoder)
 
     def rm_tmp(self):
         """Cleanup temporary/intermediate files and directories"""
-- 
2.6.6

[PATCH 10/12] oeqa.buildperf: show skipped tests in results, too

[Markus Lehtonen]

Signed-off-by: Markus Lehtonen <markus.lehtonen@linux.intel.com>
---
 meta/lib/oeqa/buildperf/base.py | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/meta/lib/oeqa/buildperf/base.py b/meta/lib/oeqa/buildperf/base.py
index c716220..49da8f6 100644
--- a/meta/lib/oeqa/buildperf/base.py
+++ b/meta/lib/oeqa/buildperf/base.py
@@ -161,7 +161,8 @@ class BuildPerfTestResult(unittest.TextTestResult):
                       'FAIL': self.failures,
                       'ERROR': self.errors,
                       'EXP_FAIL': self.expectedFailures,
-                      'UNEXP_SUCCESS': self.unexpectedSuccesses}
+                      'UNEXP_SUCCESS': self.unexpectedSuccesses,
+                      'SKIPPED': self.skipped}
         for status, tests in result_map.items():
             for test in tests:
                 yield (status, test)
-- 
2.6.6

[PATCH 11/12] oeqa.buildperf: include buildstats file name in results.json

[Markus Lehtonen]

No need to do lsdir magic for finding buildstats when reading results.

Signed-off-by: Markus Lehtonen <markus.lehtonen@linux.intel.com>
---
 meta/lib/oeqa/buildperf/base.py       | 18 ++++++++++++++----
 meta/lib/oeqa/buildperf/test_basic.py |  7 +++----
 2 files changed, 17 insertions(+), 8 deletions(-)

diff --git a/meta/lib/oeqa/buildperf/base.py b/meta/lib/oeqa/buildperf/base.py
index 49da8f6..0b2c0f8 100644
--- a/meta/lib/oeqa/buildperf/base.py
+++ b/meta/lib/oeqa/buildperf/base.py
@@ -141,7 +141,7 @@ class BuildPerfTestResult(unittest.TextTestResult):
 
     def startTest(self, test):
         """Pre-test hook"""
-        test.out_dir = os.path.join(self.out_dir, test.name)
+        test.base_dir = self.out_dir
         os.mkdir(test.out_dir)
         log.info("Executing test %s: %s", test.name, test.shortDescription())
         self.stream.write(datetime.now().strftime("[%Y-%m-%d %H:%M:%S] "))
@@ -298,7 +298,7 @@ class BuildPerfTestCase(unittest.TestCase):
     def __init__(self, *args, **kwargs):
         super(BuildPerfTestCase, self).__init__(*args, **kwargs)
         self.name = self._testMethodName
-        self.out_dir = None
+        self.base_dir = None
         self.start_time = None
         self.elapsed_time = None
         self.measurements = []
@@ -308,6 +308,10 @@ class BuildPerfTestCase(unittest.TestCase):
         self.times = []
         self.sizes = []
 
+    @property
+    def out_dir(self):
+        return os.path.join(self.base_dir, self.name)
+
     def setUp(self):
         """Set-up fixture for each test"""
         if self.build_target:
@@ -332,7 +336,7 @@ class BuildPerfTestCase(unittest.TestCase):
             log.error("Command failed: %s", err.retcode)
             raise
 
-    def measure_cmd_resources(self, cmd, name, legend):
+    def measure_cmd_resources(self, cmd, name, legend, save_bs=False):
         """Measure system resource usage of a command"""
         def _worker(data_q, cmd, **kwargs):
             """Worker process for measuring resources"""
@@ -387,6 +391,11 @@ class BuildPerfTestCase(unittest.TestCase):
                                  'elapsed_time': etime,
                                  'rusage': data['rusage'],
                                  'iostat': data['iostat']}
+        if save_bs:
+            bs_file = self.save_buildstats(legend)
+            measurement['values']['buildstats_file'] = \
+                    os.path.relpath(bs_file, self.base_dir)
+
         self.measurements.append(measurement)
 
         # Append to 'times' array for globalres log
@@ -474,12 +483,13 @@ class BuildPerfTestCase(unittest.TestCase):
             buildstats.append(recipe_bs)
 
         # Write buildstats into json file
-        postfix = '.' + label if label else ''
+        postfix = '.' + str_to_fn(label) if label else ''
         postfix += '.json'
         outfile = os.path.join(self.out_dir, 'buildstats' + postfix)
         with open(outfile, 'w') as fobj:
             json.dump(buildstats, fobj, indent=4, sort_keys=True,
                       cls=ResultsJsonEncoder)
+        return outfile
 
     def rm_tmp(self):
         """Cleanup temporary/intermediate files and directories"""
diff --git a/meta/lib/oeqa/buildperf/test_basic.py b/meta/lib/oeqa/buildperf/test_basic.py
index 25dbfb0..e448ed1 100644
--- a/meta/lib/oeqa/buildperf/test_basic.py
+++ b/meta/lib/oeqa/buildperf/test_basic.py
@@ -28,9 +28,8 @@ class Test1P1(BuildPerfTestCase):
         self.rm_cache()
         self.sync()
         self.measure_cmd_resources(['bitbake', self.build_target], 'build',
-                                   'bitbake ' + self.build_target)
+                                   'bitbake ' + self.build_target, save_bs=True)
         self.measure_disk_usage(self.bb_vars['TMPDIR'], 'tmpdir', 'tmpdir')
-        self.save_buildstats()
 
 
 class Test1P2(BuildPerfTestCase):
@@ -62,11 +61,11 @@ class Test1P3(BuildPerfTestCase):
             self.sync()
             cmd = ['bitbake', '-R', postfile, self.build_target]
             self.measure_cmd_resources(cmd, 'build',
-                                       'bitbake' + self.build_target)
+                                       'bitbake' + self.build_target,
+                                       save_bs=True)
             self.measure_disk_usage(self.bb_vars['TMPDIR'], 'tmpdir', 'tmpdir')
         finally:
             os.unlink(postfile)
-        self.save_buildstats()
 
 
 class Test2(BuildPerfTestCase):
-- 
2.6.6

[PATCH 12/12] oeqa.buildperf: include commands log file name in results.json

[Markus Lehtonen]

Signed-off-by: Markus Lehtonen <markus.lehtonen@linux.intel.com>
---
 meta/lib/oeqa/buildperf/base.py | 14 +++++++++-----
 1 file changed, 9 insertions(+), 5 deletions(-)

diff --git a/meta/lib/oeqa/buildperf/base.py b/meta/lib/oeqa/buildperf/base.py
index 0b2c0f8..be3a946 100644
--- a/meta/lib/oeqa/buildperf/base.py
+++ b/meta/lib/oeqa/buildperf/base.py
@@ -220,6 +220,8 @@ class BuildPerfTestResult(unittest.TextTestResult):
                                 'status': status,
                                 'start_time': test.start_time,
                                 'elapsed_time': test.elapsed_time,
+                                'cmd_log_file': os.path.relpath(test.cmd_log_file,
+                                                                self.out_dir),
                                 'measurements': test.measurements}
         results['tests'] = tests
 
@@ -312,6 +314,10 @@ class BuildPerfTestCase(unittest.TestCase):
     def out_dir(self):
         return os.path.join(self.base_dir, self.name)
 
+    @property
+    def cmd_log_file(self):
+        return os.path.join(self.out_dir, 'commands.log')
+
     def setUp(self):
         """Set-up fixture for each test"""
         if self.build_target:
@@ -328,9 +334,8 @@ class BuildPerfTestCase(unittest.TestCase):
         """Run a command and log it's output"""
         cmd_str = cmd if isinstance(cmd, str) else ' '.join(cmd)
         log.info("Logging command: %s", cmd_str)
-        cmd_log = os.path.join(self.out_dir, 'commands.log')
         try:
-            with open(cmd_log, 'a') as fobj:
+            with open(self.cmd_log_file, 'a') as fobj:
                 runCmd2(cmd, stdout=fobj)
         except CommandError as err:
             log.error("Command failed: %s", err.retcode)
@@ -368,9 +373,8 @@ class BuildPerfTestCase(unittest.TestCase):
         cmd_str = cmd if isinstance(cmd, str) else ' '.join(cmd)
         log.info("Timing command: %s", cmd_str)
         data_q = SimpleQueue()
-        cmd_log = os.path.join(self.out_dir, 'commands.log')
         try:
-            with open(cmd_log, 'a') as fobj:
+            with open(self.cmd_log_file, 'a') as fobj:
                 proc = Process(target=_worker, args=(data_q, cmd,),
                                kwargs={'stdout': fobj})
                 proc.start()
@@ -380,7 +384,7 @@ class BuildPerfTestCase(unittest.TestCase):
                 raise data
         except CommandError:
             log.error("Command '%s' failed, see %s for more details", cmd_str,
-                      cmd_log)
+                      self.cmd_log_file)
             raise
         etime = data['elapsed_time']
 
-- 
2.6.6