1 files changed, 411 insertions, 0 deletions

diff --git a/scripts/buildstats-diff b/scripts/buildstats-diff
new file mode 100755
index 0000000000..8ee2aaf626
--- /dev/null
+++ b/scripts/buildstats-diff
@@ -0,0 +1,411 @@
+#!/usr/bin/python3
+#
+# Script for comparing buildstats from two different builds
+#
+# Copyright (c) 2016, Intel Corporation.
+#
+# This program is free software; you can redistribute it and/or modify it
+# under the terms and conditions of the GNU General Public License,
+# version 2, as published by the Free Software Foundation.
+#
+# This program is distributed in the hope 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.
+#
+import argparse
+import glob
+import json
+import logging
+import os
+import re
+import sys
+from collections import namedtuple
+from datetime import datetime, timedelta, tzinfo
+from operator import attrgetter
+
+# Setup logging
+logging.basicConfig(level=logging.INFO)
+log = logging.getLogger()
+
+
+class TimeZone(tzinfo):
+    """Simple fixed-offset tzinfo"""
+    def __init__(self, seconds, name):
+        self._offset = timedelta(seconds=seconds)
+        self._name = name
+
+    def utcoffset(self, dt):
+        return self._offset
+
+    def tzname(self, dt):
+        return self._name
+
+    def dst(self, dt):
+        return None
+
+TIMEZONES = {'UTC': TimeZone(0, 'UTC'),
+             'EET': TimeZone(7200, 'EET'),
+             'EEST': TimeZone(10800, 'EEST')}
+
+
+taskdiff_fields = ('pkg', 'pkg_op', 'task', 'task_op', 'cputime1', 'cputime2',
+                   'absdiff', 'reldiff')
+TaskDiff = namedtuple('TaskDiff', ' '.join(taskdiff_fields))
+
+
+def to_datetime_obj(obj):
+    """Helper for getting timestamps in datetime format"""
+    if isinstance(obj, datetime):
+        return obj
+    else:
+        return datetime.utcfromtimestamp(obj).replace(tzinfo=TIMEZONES['UTC'])
+
+
+def read_buildstats_file(buildstat_file):
+    """Convert buildstat text file into dict/json"""
+    bs_json = {'iostat': {},
+               'rusage': {},
+               'child_rusage': {}}
+    log.debug("Reading task buildstats from %s", buildstat_file)
+    with open(buildstat_file) as fobj:
+        for line in fobj.readlines():
+            key, val = line.split(':', 1)
+            val = val.strip()
+            if key == 'Started':
+                start_time = to_datetime_obj(float(val))
+                bs_json['start_time'] = start_time
+            elif key == 'Ended':
+                end_time = to_datetime_obj(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
+
+
+def read_buildstats_dir(bs_dir):
+    """Read buildstats directory"""
+    def split_nevr(nevr):
+        """Split name and version information from recipe "nevr" string"""
+        n_e_v, revision = nevr.rsplit('-', 1)
+        match = re.match(r'^(?P<name>\S+)-((?P<epoch>[0-9]{1,5})_)?(?P<version>[0-9]\S*)$',
+                         n_e_v)
+        if not match:
+            # If we're not able to parse a version starting with a number, just
+            # take the part after last dash
+            match = re.match(r'^(?P<name>\S+)-((?P<epoch>[0-9]{1,5})_)?(?P<version>[^-]+)$',
+                             n_e_v)
+        name = match.group('name')
+        version = match.group('version')
+        epoch = match.group('epoch')
+        return name, epoch, version, revision
+
+    if os.path.isfile(os.path.join(bs_dir, 'build_stats')):
+        top_dir = bs_dir
+    else:
+        subdirs = sorted(glob.glob(bs_dir + '/*'))
+        if len(subdirs) > 1:
+            log.warning("Multiple buildstats found, using the first one")
+        top_dir = subdirs[0]
+    log.debug("Reading buildstats directory %s", top_dir)
+    subdirs = os.listdir(top_dir)
+
+    # Handle "old" style directory structure
+    if len(subdirs) == 1 and re.match('^20[0-9]{12}$', subdirs[0]):
+        top_dir = os.path.join(top_dir, subdirs[0])
+        subdirs = os.listdir(top_dir)
+
+    buildstats = {}
+    for dirname in subdirs:
+        recipe_dir = os.path.join(top_dir, dirname)
+        if not os.path.isdir(recipe_dir):
+            continue
+        name, epoch, version, revision = split_nevr(dirname)
+        recipe_bs = {'nevr': dirname,
+                     'name': name,
+                     'epoch': epoch,
+                     'version': version,
+                     'revision': revision,
+                     'tasks': {}}
+        for task in os.listdir(recipe_dir):
+            recipe_bs['tasks'][task] = read_buildstats_file(
+                    os.path.join(recipe_dir, task))
+        if name in buildstats:
+            log.error("Cannot handle multiple versions of the same package (%s)",
+                      name)
+            sys.exit(1)
+        buildstats[name] = recipe_bs
+
+    return buildstats
+
+
+def read_buildstats_json(path):
+    """Read buildstats from JSON file"""
+    buildstats = {}
+    with open(path) as fobj:
+        bs_json = json.load(fobj)
+    for recipe_bs in bs_json:
+        if recipe_bs['name'] in buildstats:
+            log.error("Cannot handle multiple versions of the same package (%s)",
+                      recipe_bs['name'])
+            sys.exit(1)
+
+        if recipe_bs['epoch'] is None:
+            recipe_bs['nevr'] = "{}-{}-{}".format(recipe_bs['name'], recipe_bs['version'], recipe_bs['revision'])
+        else:
+            recipe_bs['nevr'] = "{}-{}_{}-{}".format(recipe_bs['name'], recipe_bs['epoch'], recipe_bs['version'], recipe_bs['revision'])
+        buildstats[recipe_bs['name']] = recipe_bs
+
+    return buildstats
+
+
+def read_buildstats(path):
+    """Read buildstats"""
+    if os.path.isfile(path):
+        return read_buildstats_json(path)
+    else:
+        return read_buildstats_dir(path)
+
+
+def print_ver_diff(bs1, bs2):
+    """Print package version differences"""
+    pkgs1 = set(bs1.keys())
+    pkgs2 = set(bs2.keys())
+    new_pkgs = pkgs2 - pkgs1
+    deleted_pkgs = pkgs1 - pkgs2
+
+    echanged = []
+    vchanged = []
+    rchanged = []
+    unchanged = []
+    common_pkgs = pkgs2.intersection(pkgs1)
+    if common_pkgs:
+        for pkg in common_pkgs:
+            if bs1[pkg]['epoch'] != bs2[pkg]['epoch']:
+                echanged.append(pkg)
+            elif bs1[pkg]['version'] != bs2[pkg]['version']:
+                vchanged.append(pkg)
+            elif bs1[pkg]['revision'] != bs2[pkg]['revision']:
+                rchanged.append(pkg)
+            else:
+                unchanged.append(pkg)
+
+    maxlen = max([len(pkg) for pkg in pkgs1.union(pkgs2)])
+    fmt_str = "  {:{maxlen}} ({})"
+#    if unchanged:
+#        print("\nUNCHANGED PACKAGES:")
+#        print("-------------------")
+#        maxlen = max([len(pkg) for pkg in unchanged])
+#        for pkg in sorted(unchanged):
+#            print(fmt_str.format(pkg, bs2[pkg]['nevr'], maxlen=maxlen))
+
+    if new_pkgs:
+        print("\nNEW PACKAGES:")
+        print("-------------")
+        for pkg in sorted(new_pkgs):
+            print(fmt_str.format(pkg, bs2[pkg]['nevr'], maxlen=maxlen))
+
+    if deleted_pkgs:
+        print("\nDELETED PACKAGES:")
+        print("-----------------")
+        for pkg in sorted(deleted_pkgs):
+            print(fmt_str.format(pkg, bs1[pkg]['nevr'], maxlen=maxlen))
+
+    fmt_str = "  {0:{maxlen}} {1:<20}    ({2})"
+    if rchanged:
+        print("\nREVISION CHANGED:")
+        print("-----------------")
+        for pkg in sorted(rchanged):
+            field1 = "{} -> {}".format(pkg, bs1[pkg]['revision'], bs2[pkg]['revision'])
+            field2 = "{} -> {}".format(bs1[pkg]['nevr'], bs2[pkg]['nevr'])
+            print(fmt_str.format(pkg, field1, field2, maxlen=maxlen))
+
+    if vchanged:
+        print("\nVERSION CHANGED:")
+        print("----------------")
+        for pkg in sorted(vchanged):
+            field1 = "{} -> {}".format(bs1[pkg]['version'], bs2[pkg]['version'])
+            field2 = "{} -> {}".format(bs1[pkg]['nevr'], bs2[pkg]['nevr'])
+            print(fmt_str.format(pkg, field1, field2, maxlen=maxlen))
+
+    if echanged:
+        print("\nEPOCH CHANGED:")
+        print("--------------")
+        for pkg in sorted(echanged):
+            field1 = "{} -> {}".format(pkg, bs1[pkg]['epoch'], bs2[pkg]['epoch'])
+            field2 = "{} -> {}".format(bs1[pkg]['nevr'], bs2[pkg]['nevr'])
+            print(fmt_str.format(pkg, field1, field2, maxlen=maxlen))
+
+
+def task_time(task):
+    """Calculate sum of user and system time taken by a task"""
+    cputime = task['rusage']['ru_stime'] + task['rusage']['ru_utime'] + \
+              task['child_rusage']['ru_stime'] + task['child_rusage']['ru_utime']
+    return cputime
+
+
+def print_task_diff(bs1, bs2, min_cputime=0, min_timediff=0, sort_by=('absdiff',)):
+    """Diff task execution times"""
+    tasks_diff = []
+    pkg_maxlen = 0
+    task_maxlen = 0
+
+    pkgs = set(bs1.keys()).union(set(bs2.keys()))
+    for pkg in pkgs:
+        if len(pkg) > pkg_maxlen:
+            pkg_maxlen = len(pkg)
+        tasks1 = bs1[pkg]['tasks'] if pkg in bs1 else {}
+        tasks2 = bs2[pkg]['tasks'] if pkg in bs2 else {}
+        if not tasks1:
+            pkg_op = '+ '
+        elif not tasks2:
+            pkg_op = '- '
+        else:
+            pkg_op = '  '
+
+        for task in set(tasks1.keys()).union(set(tasks2.keys())):
+            if len(task) > task_maxlen:
+                task_maxlen = len(task)
+
+            t1 = task_time(bs1[pkg]['tasks'][task]) if task in tasks1 else 0
+            t2 = task_time(bs2[pkg]['tasks'][task]) if task in tasks2 else 0
+            task_op = '  '
+            if t1 == 0:
+                reldiff = float('inf')
+                task_op = '+ '
+            else:
+                reldiff = 100 * (t2 - t1) / t1
+                if t2 == 0:
+                    task_op = '- '
+
+            tasks_diff.append(TaskDiff(pkg, pkg_op, task, task_op, t1, t2, t2-t1, reldiff))
+
+    if min_cputime:
+        print("Ignoring tasks shorter than {}s".format(min_cputime))
+    if min_timediff:
+        print("Ignoring time differences shorter than {}s".format(min_timediff))
+
+    print()
+    print("  {:{pkg_maxlen}}   {:{task_maxlen}} {:>8} {:>10} {:>10}    {}".format(
+            'PKG', 'TASK', 'ABSDIFF', 'RELDIFF', 'CPUTIME1', 'CPUTIME2',
+            pkg_maxlen=pkg_maxlen, task_maxlen=task_maxlen))
+
+    # Sort our list
+    for field in reversed(sort_by):
+        if field.startswith('-'):
+            field = field[1:]
+            reverse = True
+        else:
+            reverse = False
+        tasks_diff = sorted(tasks_diff, key=attrgetter(field), reverse=reverse)
+
+    for diff in tasks_diff:
+        cputime = max(diff.cputime1, diff.cputime2)
+        if cputime > min_cputime:
+            if abs(diff.absdiff) > min_timediff:
+                task_prefix = diff.task_op if diff.pkg_op == '  ' else '  '
+                print("{}{:{pkg_maxlen}} {}{:{task_maxlen}} {:+7.1f}s {:+9.1f}% {:9.1f}s -> {:.1f}s".format(
+                        diff.pkg_op, diff.pkg, task_prefix, diff.task, diff.absdiff, diff.reldiff, diff.cputime1, diff.cputime2,
+                        pkg_maxlen=pkg_maxlen, task_maxlen=task_maxlen))
+            else:
+                log.debug("Filtering out %s (difference of %0.1fs)", task, diff.absdiff)
+        else:
+            log.debug("Filtering out %s (%0.1fs)", task, cputime)
+
+
+def print_timediff_summary(bs1, bs2):
+    """Print summary of the timediffs"""
+    def total_cputime(buildstats):
+        sum = 0.0
+        for recipe_data in buildstats.values():
+            for task_data in recipe_data['tasks'].values():
+                sum += task_time(task_data)
+        return sum
+
+    def hms_time(secs):
+        """Get time in human-readable HH:MM:SS format"""
+        h = int(secs / 3600)
+        m = int((secs % 3600) / 60)
+        s = secs % 60
+        if h == 0:
+            return "{:02d}:{:04.1f}".format(m, s)
+        else:
+            return "{:d}:{:02d}:{:04.1f}".format(h, m, s)
+
+    total1 = total_cputime(bs1)
+    total2 = total_cputime(bs2)
+    print("\nCumulative CPU Time:")
+    print ("  {:+.1f}s    {:+.1f}%    {} ({:.1f}s) -> {} ({:.1f}s)".format(
+                total2 - total1, 100 * (total2-total1) / total1,
+                hms_time(total1), total1, hms_time(total2), total2))
+
+
+
+def parse_args(argv):
+    """Parse cmdline arguments"""
+    description="""
+Script for comparing buildstats of two separate builds."""
+    parser = argparse.ArgumentParser(
+            formatter_class=argparse.ArgumentDefaultsHelpFormatter,
+            description=description)
+
+    parser.add_argument('--debug', '-d', action='store_true',
+                        help="Verbose logging")
+    parser.add_argument('--ver-diff', action='store_true',
+                        help="Show package version differences and exit")
+    parser.add_argument('--min-time', default=3.0, type=float,
+                        help="Filter out tasks shorter than MIN_TIME seconds")
+    parser.add_argument('--min-timediff', default=1.0, type=float,
+                        help="Filter out tasks whose difference in cputime is "
+                             "less that  MIN_TIMEDIFF seconds")
+    parser.add_argument('--sort-by', default='absdiff',
+                        help="Comma-separated list of field sort order. "
+                             "Prepend the field name with '-' for reversed sort. "
+                             "Available fields are: {}".format(', '.join(taskdiff_fields)))
+    parser.add_argument('buildstats1', metavar='BUILDSTATS1', help="'Left' buildstat")
+    parser.add_argument('buildstats2', metavar='BUILDSTATS2', help="'Right' buildstat")
+
+    return parser.parse_args(argv)
+
+def main(argv=None):
+    """Script entry point"""
+    args = parse_args(argv)
+    if args.debug:
+        log.setLevel(logging.DEBUG)
+
+    # Validate sort fields
+    sort_by = []
+    for field in args.sort_by.split(','):
+        if field.lstrip('-') not in taskdiff_fields:
+            log.error("Invalid sort field '%s' (must be one of: %s)" %
+                      (field, ', '.join(taskdiff_fields)))
+            sys.exit(1)
+        sort_by.append(field)
+
+
+    bs1 = read_buildstats(args.buildstats1)
+    bs2 = read_buildstats(args.buildstats2)
+
+    if args.ver_diff:
+        print_ver_diff(bs1, bs2)
+    else:
+        print_task_diff(bs1, bs2, args.min_time, args.min_timediff, sort_by)
+        print_timediff_summary(bs1, bs2)
+
+    return 0
+
+if __name__ == "__main__":
+    sys.exit(main())