poky/scripts/buildstats-diff

#!/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 math 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', 'value1', 'value2', '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'])

class BSTask(dict): def init(self, *args, **kwargs): self['start_time'] = None self['elapsed_time'] = None self['status'] = None self['iostat'] = {} self['rusage'] = {} self['child_rusage'] = {} super(BSTask, self).init(*args, **kwargs)

@property
def cputime(self):
    """Sum of user and system time taken by the task"""
    return self['rusage']['ru_stime'] + self['rusage']['ru_utime'] + \
           self['child_rusage']['ru_stime'] + self['child_rusage']['ru_utime']

@property
def walltime(self):
    """Elapsed wall clock time"""
    return self['elapsed_time'].total_seconds()

@property
def read_bytes(self):
    """Bytes read from the block layer"""
    return self['iostat']['read_bytes']

@property
def write_bytes(self):
    """Bytes written to the block layer"""
    return self['iostat']['write_bytes']

@property
def read_ops(self):
    """Number of read operations on the block layer"""
    return self['rusage']['ru_inblock'] + self['child_rusage']['ru_inblock']

@property
def write_ops(self):
    """Number of write operations on the block layer"""
    return self['rusage']['ru_oublock'] + self['child_rusage']['ru_oublock']

def read_buildstats_file(buildstat_file): """Convert buildstat text file into dict/json""" bs_task = BSTask() 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_task['start_time'] = start_time elif key == 'Ended': end_time = to_datetime_obj(float(val)) elif key.startswith('IO '): split = key.split() bs_task['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_task[ru_type][ru_key] = val elif key == 'Status': bs_task['status'] = val bs_task['elapsed_time'] = end_time - start_time return bs_task

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\S+)-((?P[0-9]{1,5}))?(?P[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\S+)-((?P[0-9]{1,5}))?(?P[^-]+)$', 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
elif os.path.exists(bs_dir):
    subdirs = sorted(glob.glob(bs_dir + '/*'))
    if len(subdirs) > 1:
        log.warning("Multiple buildstats found, using the first one")
    top_dir = subdirs[0]
else:
    log.error("No such directory: %s", bs_dir)
    sys.exit(1)
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'])

    for task, data in recipe_bs['tasks'].copy().items():
        recipe_bs['tasks'][task] = BSTask(data)

    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 print_task_diff(bs1, bs2, val_type, min_val=0, min_absdiff=0, sort_by=('absdiff',)): """Diff task execution times""" def val_to_str(val, human_readable=False): """Convert raw value to printable string""" 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)

    if 'time' in val_type:
        if human_readable:
            return hms_time(val)
        else:
            return "{:.1f}s".format(val)
    elif 'bytes' in val_type and human_readable:
            prefix = ['', 'Ki', 'Mi', 'Gi', 'Ti', 'Pi']
            dec = int(math.log(val, 2) / 10)
            prec = 1 if dec > 0 else 0
            return "{:.{prec}f}{}B".format(val / (2 ** (10 * dec)),
                                           prefix[dec], prec=prec)
    elif 'ops' in val_type and human_readable:
            prefix = ['', 'k', 'M', 'G', 'T', 'P']
            dec = int(math.log(val, 1000))
            prec = 1 if dec > 0 else 0
            return "{:.{prec}f}{}ops".format(val / (1000 ** dec),
                                             prefix[dec], prec=prec)
    return str(int(val))

def sum_vals(buildstats):
    """Get cumulative sum of all tasks"""
    total = 0.0
    for recipe_data in buildstats.values():
        for bs_task in recipe_data['tasks'].values():
            total += getattr(bs_task, val_type)
    return total

tasks_diff = []

if min_val:
    print("Ignoring tasks less than {} ({})".format(
            val_to_str(min_val, True), val_to_str(min_val)))
if min_absdiff:
    print("Ignoring differences less than {} ({})".format(
            val_to_str(min_absdiff, True), val_to_str(min_absdiff)))

# Prepare the data
pkgs = set(bs1.keys()).union(set(bs2.keys()))
for pkg in pkgs:
    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())):
        task_op = '  '
        if task in tasks1:
            val1 = getattr(bs1[pkg]['tasks'][task], val_type)
        else:
            task_op = '+ '
            val1 = 0
        if task in tasks2:
            val2 = getattr(bs2[pkg]['tasks'][task], val_type)
        else:
            val2 = 0
            task_op = '- '

        if val1 == 0:
            reldiff = float('inf')
        else:
            reldiff = 100 * (val2 - val1) / val1

        if max(val1, val2) < min_val:
            log.debug("Filtering out %s:%s (%s)", pkg, task,
                      val_to_str(max(val1, val2)))
            continue
        if abs(val2 - val1) < min_absdiff:
            log.debug("Filtering out %s:%s (difference of %s)", pkg, task,
                      val_to_str(val2-val1))
            continue
        tasks_diff.append(TaskDiff(pkg, pkg_op, task, task_op, val1, val2,
                                   val2-val1, reldiff))

# 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)

linedata = [('  ', 'PKG', '  ', 'TASK', 'ABSDIFF', 'RELDIFF',
            val_type.upper() + '1', val_type.upper() + '2')]
field_lens = dict([('len_{}'.format(i), len(f)) for i, f in enumerate(linedata[0])])

# Prepare fields in string format and measure field lengths
for diff in tasks_diff:
    task_prefix = diff.task_op if diff.pkg_op == '  ' else '  '
    linedata.append((diff.pkg_op, diff.pkg, task_prefix, diff.task,
                     val_to_str(diff.absdiff),
                     '{:+.1f}%'.format(diff.reldiff),
                     val_to_str(diff.value1),
                     val_to_str(diff.value2)))
    for i, field in enumerate(linedata[-1]):
        key = 'len_{}'.format(i)
        if len(field) > field_lens[key]:
            field_lens[key] = len(field)

# Print data
print()
for fields in linedata:
    print("{:{len_0}}{:{len_1}}  {:{len_2}}{:{len_3}}  {:>{len_4}}  {:>{len_5}}  {:>{len_6}} -> {:{len_7}}".format(
            *fields, **field_lens))

# Print summary of the diffs
total1 = sum_vals(bs1)
total2 = sum_vals(bs2)
print("\nCumulative {}:".format(val_type))
print ("  {}    {:+.1f}%    {} ({}) -> {} ({})".format(
            val_to_str(total2 - total1), 100 * (total2-total1) / total1,
            val_to_str(total1, True), val_to_str(total1),
            val_to_str(total2, True), val_to_str(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)

min_val_defaults = {'cputime': 3.0,
                    'read_bytes': 524288,
                    'write_bytes': 524288,
                    'read_ops': 500,
                    'write_ops': 500,
                    'walltime': 5}
min_absdiff_defaults = {'cputime': 1.0,
                        'read_bytes': 131072,
                        'write_bytes': 131072,
                        'read_ops': 50,
                        'write_ops': 50,
                        'walltime': 2}

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('--diff-attr', default='cputime',
                    choices=min_val_defaults.keys(),
                    help="Buildstat attribute which to compare")
parser.add_argument('--min-val', default=min_val_defaults, type=float,
                    help="Filter out tasks less than MIN_VAL. "
                         "Default depends on --diff-attr.")
parser.add_argument('--min-absdiff', default=min_absdiff_defaults, type=float,
                    help="Filter out tasks whose difference is less than "
                         "MIN_ABSDIFF, Default depends on --diff-attr.")
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")

args = parser.parse_args(argv)

# Handle defaults for the filter arguments
if args.min_val is min_val_defaults:
    args.min_val = min_val_defaults[args.diff_attr]
if args.min_absdiff is min_absdiff_defaults:
    args.min_absdiff = min_absdiff_defaults[args.diff_attr]

return args

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.diff_attr, args.min_val,
                    args.min_absdiff, sort_by)

return 0

if name == "main": sys.exit(main())