buildstats-diff 20 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536
  1. #!/usr/bin/python3
  2. #
  3. # Script for comparing buildstats from two different builds
  4. #
  5. # Copyright (c) 2016, Intel Corporation.
  6. #
  7. # This program is free software; you can redistribute it and/or modify it
  8. # under the terms and conditions of the GNU General Public License,
  9. # version 2, as published by the Free Software Foundation.
  10. #
  11. # This program is distributed in the hope it will be useful, but WITHOUT
  12. # ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
  13. # FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for
  14. # more details.
  15. #
  16. import argparse
  17. import glob
  18. import json
  19. import logging
  20. import math
  21. import os
  22. import re
  23. import sys
  24. from collections import namedtuple
  25. from operator import attrgetter
  26. # Setup logging
  27. logging.basicConfig(level=logging.INFO, format="%(levelname)s: %(message)s")
  28. log = logging.getLogger()
  29. class ScriptError(Exception):
  30. """Exception for internal error handling of this script"""
  31. pass
  32. taskdiff_fields = ('pkg', 'pkg_op', 'task', 'task_op', 'value1', 'value2',
  33. 'absdiff', 'reldiff')
  34. TaskDiff = namedtuple('TaskDiff', ' '.join(taskdiff_fields))
  35. class BSTask(dict):
  36. def __init__(self, *args, **kwargs):
  37. self['start_time'] = None
  38. self['elapsed_time'] = None
  39. self['status'] = None
  40. self['iostat'] = {}
  41. self['rusage'] = {}
  42. self['child_rusage'] = {}
  43. super(BSTask, self).__init__(*args, **kwargs)
  44. @property
  45. def cputime(self):
  46. """Sum of user and system time taken by the task"""
  47. return self['rusage']['ru_stime'] + self['rusage']['ru_utime'] + \
  48. self['child_rusage']['ru_stime'] + self['child_rusage']['ru_utime']
  49. @property
  50. def walltime(self):
  51. """Elapsed wall clock time"""
  52. return self['elapsed_time']
  53. @property
  54. def read_bytes(self):
  55. """Bytes read from the block layer"""
  56. return self['iostat']['read_bytes']
  57. @property
  58. def write_bytes(self):
  59. """Bytes written to the block layer"""
  60. return self['iostat']['write_bytes']
  61. @property
  62. def read_ops(self):
  63. """Number of read operations on the block layer"""
  64. return self['rusage']['ru_inblock'] + self['child_rusage']['ru_inblock']
  65. @property
  66. def write_ops(self):
  67. """Number of write operations on the block layer"""
  68. return self['rusage']['ru_oublock'] + self['child_rusage']['ru_oublock']
  69. def read_buildstats_file(buildstat_file):
  70. """Convert buildstat text file into dict/json"""
  71. bs_task = BSTask()
  72. log.debug("Reading task buildstats from %s", buildstat_file)
  73. with open(buildstat_file) as fobj:
  74. for line in fobj.readlines():
  75. key, val = line.split(':', 1)
  76. val = val.strip()
  77. if key == 'Started':
  78. start_time = float(val)
  79. bs_task['start_time'] = start_time
  80. elif key == 'Ended':
  81. end_time = float(val)
  82. elif key.startswith('IO '):
  83. split = key.split()
  84. bs_task['iostat'][split[1]] = int(val)
  85. elif key.find('rusage') >= 0:
  86. split = key.split()
  87. ru_key = split[-1]
  88. if ru_key in ('ru_stime', 'ru_utime'):
  89. val = float(val)
  90. else:
  91. val = int(val)
  92. ru_type = 'rusage' if split[0] == 'rusage' else \
  93. 'child_rusage'
  94. bs_task[ru_type][ru_key] = val
  95. elif key == 'Status':
  96. bs_task['status'] = val
  97. bs_task['elapsed_time'] = end_time - start_time
  98. return bs_task
  99. def read_buildstats_dir(bs_dir):
  100. """Read buildstats directory"""
  101. def split_nevr(nevr):
  102. """Split name and version information from recipe "nevr" string"""
  103. n_e_v, revision = nevr.rsplit('-', 1)
  104. match = re.match(r'^(?P<name>\S+)-((?P<epoch>[0-9]{1,5})_)?(?P<version>[0-9]\S*)$',
  105. n_e_v)
  106. if not match:
  107. # If we're not able to parse a version starting with a number, just
  108. # take the part after last dash
  109. match = re.match(r'^(?P<name>\S+)-((?P<epoch>[0-9]{1,5})_)?(?P<version>[^-]+)$',
  110. n_e_v)
  111. name = match.group('name')
  112. version = match.group('version')
  113. epoch = match.group('epoch')
  114. return name, epoch, version, revision
  115. if not os.path.isfile(os.path.join(bs_dir, 'build_stats')):
  116. raise ScriptError("{} does not look like a buildstats directory".format(bs_dir))
  117. log.debug("Reading buildstats directory %s", bs_dir)
  118. buildstats = {}
  119. subdirs = os.listdir(bs_dir)
  120. for dirname in subdirs:
  121. recipe_dir = os.path.join(bs_dir, dirname)
  122. if not os.path.isdir(recipe_dir):
  123. continue
  124. name, epoch, version, revision = split_nevr(dirname)
  125. recipe_bs = {'nevr': dirname,
  126. 'name': name,
  127. 'epoch': epoch,
  128. 'version': version,
  129. 'revision': revision,
  130. 'tasks': {}}
  131. for task in os.listdir(recipe_dir):
  132. recipe_bs['tasks'][task] = [read_buildstats_file(
  133. os.path.join(recipe_dir, task))]
  134. if name in buildstats:
  135. raise ScriptError("Cannot handle multiple versions of the same "
  136. "package ({})".format(name))
  137. buildstats[name] = recipe_bs
  138. return buildstats
  139. def bs_append(dst, src):
  140. """Append data from another buildstats"""
  141. if set(dst.keys()) != set(src.keys()):
  142. raise ScriptError("Refusing to join buildstats, set of packages is "
  143. "different")
  144. for pkg, data in dst.items():
  145. if data['nevr'] != src[pkg]['nevr']:
  146. raise ScriptError("Refusing to join buildstats, package version "
  147. "differs: {} vs. {}".format(data['nevr'], src[pkg]['nevr']))
  148. if set(data['tasks'].keys()) != set(src[pkg]['tasks'].keys()):
  149. raise ScriptError("Refusing to join buildstats, set of tasks "
  150. "in {} differ".format(pkg))
  151. for taskname, taskdata in data['tasks'].items():
  152. taskdata.extend(src[pkg]['tasks'][taskname])
  153. def read_buildstats_json(path):
  154. """Read buildstats from JSON file"""
  155. buildstats = {}
  156. with open(path) as fobj:
  157. bs_json = json.load(fobj)
  158. for recipe_bs in bs_json:
  159. if recipe_bs['name'] in buildstats:
  160. raise ScriptError("Cannot handle multiple versions of the same "
  161. "package ({})".format(recipe_bs['name']))
  162. if recipe_bs['epoch'] is None:
  163. recipe_bs['nevr'] = "{}-{}-{}".format(recipe_bs['name'], recipe_bs['version'], recipe_bs['revision'])
  164. else:
  165. recipe_bs['nevr'] = "{}-{}_{}-{}".format(recipe_bs['name'], recipe_bs['epoch'], recipe_bs['version'], recipe_bs['revision'])
  166. for task, data in recipe_bs['tasks'].copy().items():
  167. recipe_bs['tasks'][task] = [BSTask(data)]
  168. buildstats[recipe_bs['name']] = recipe_bs
  169. return buildstats
  170. def read_buildstats(path, multi):
  171. """Read buildstats"""
  172. if not os.path.exists(path):
  173. raise ScriptError("No such file or directory: {}".format(path))
  174. if os.path.isfile(path):
  175. return read_buildstats_json(path)
  176. if os.path.isfile(os.path.join(path, 'build_stats')):
  177. return read_buildstats_dir(path)
  178. # Handle a non-buildstat directory
  179. subpaths = sorted(glob.glob(path + '/*'))
  180. if len(subpaths) > 1:
  181. if multi:
  182. log.info("Averaging over {} buildstats from {}".format(
  183. len(subpaths), path))
  184. else:
  185. raise ScriptError("Multiple buildstats found in '{}'. Please give "
  186. "a single buildstat directory of use the --multi "
  187. "option".format(path))
  188. bs = None
  189. for subpath in subpaths:
  190. if os.path.isfile(subpath):
  191. tmpbs = read_buildstats_json(subpath)
  192. else:
  193. tmpbs = read_buildstats_dir(subpath)
  194. if not bs:
  195. bs = tmpbs
  196. else:
  197. log.debug("Joining buildstats")
  198. bs_append(bs, tmpbs)
  199. if not bs:
  200. raise ScriptError("No buildstats found under {}".format(path))
  201. return bs
  202. def print_ver_diff(bs1, bs2):
  203. """Print package version differences"""
  204. pkgs1 = set(bs1.keys())
  205. pkgs2 = set(bs2.keys())
  206. new_pkgs = pkgs2 - pkgs1
  207. deleted_pkgs = pkgs1 - pkgs2
  208. echanged = []
  209. vchanged = []
  210. rchanged = []
  211. unchanged = []
  212. common_pkgs = pkgs2.intersection(pkgs1)
  213. if common_pkgs:
  214. for pkg in common_pkgs:
  215. if bs1[pkg]['epoch'] != bs2[pkg]['epoch']:
  216. echanged.append(pkg)
  217. elif bs1[pkg]['version'] != bs2[pkg]['version']:
  218. vchanged.append(pkg)
  219. elif bs1[pkg]['revision'] != bs2[pkg]['revision']:
  220. rchanged.append(pkg)
  221. else:
  222. unchanged.append(pkg)
  223. maxlen = max([len(pkg) for pkg in pkgs1.union(pkgs2)])
  224. fmt_str = " {:{maxlen}} ({})"
  225. # if unchanged:
  226. # print("\nUNCHANGED PACKAGES:")
  227. # print("-------------------")
  228. # maxlen = max([len(pkg) for pkg in unchanged])
  229. # for pkg in sorted(unchanged):
  230. # print(fmt_str.format(pkg, bs2[pkg]['nevr'], maxlen=maxlen))
  231. if new_pkgs:
  232. print("\nNEW PACKAGES:")
  233. print("-------------")
  234. for pkg in sorted(new_pkgs):
  235. print(fmt_str.format(pkg, bs2[pkg]['nevr'], maxlen=maxlen))
  236. if deleted_pkgs:
  237. print("\nDELETED PACKAGES:")
  238. print("-----------------")
  239. for pkg in sorted(deleted_pkgs):
  240. print(fmt_str.format(pkg, bs1[pkg]['nevr'], maxlen=maxlen))
  241. fmt_str = " {0:{maxlen}} {1:<20} ({2})"
  242. if rchanged:
  243. print("\nREVISION CHANGED:")
  244. print("-----------------")
  245. for pkg in sorted(rchanged):
  246. field1 = "{} -> {}".format(pkg, bs1[pkg]['revision'], bs2[pkg]['revision'])
  247. field2 = "{} -> {}".format(bs1[pkg]['nevr'], bs2[pkg]['nevr'])
  248. print(fmt_str.format(pkg, field1, field2, maxlen=maxlen))
  249. if vchanged:
  250. print("\nVERSION CHANGED:")
  251. print("----------------")
  252. for pkg in sorted(vchanged):
  253. field1 = "{} -> {}".format(bs1[pkg]['version'], bs2[pkg]['version'])
  254. field2 = "{} -> {}".format(bs1[pkg]['nevr'], bs2[pkg]['nevr'])
  255. print(fmt_str.format(pkg, field1, field2, maxlen=maxlen))
  256. if echanged:
  257. print("\nEPOCH CHANGED:")
  258. print("--------------")
  259. for pkg in sorted(echanged):
  260. field1 = "{} -> {}".format(bs1[pkg]['epoch'], bs2[pkg]['epoch'])
  261. field2 = "{} -> {}".format(bs1[pkg]['nevr'], bs2[pkg]['nevr'])
  262. print(fmt_str.format(pkg, field1, field2, maxlen=maxlen))
  263. def print_task_diff(bs1, bs2, val_type, min_val=0, min_absdiff=0, sort_by=('absdiff',)):
  264. """Diff task execution times"""
  265. def val_to_str(val, human_readable=False):
  266. """Convert raw value to printable string"""
  267. def hms_time(secs):
  268. """Get time in human-readable HH:MM:SS format"""
  269. h = int(secs / 3600)
  270. m = int((secs % 3600) / 60)
  271. s = secs % 60
  272. if h == 0:
  273. return "{:02d}:{:04.1f}".format(m, s)
  274. else:
  275. return "{:d}:{:02d}:{:04.1f}".format(h, m, s)
  276. if 'time' in val_type:
  277. if human_readable:
  278. return hms_time(val)
  279. else:
  280. return "{:.1f}s".format(val)
  281. elif 'bytes' in val_type and human_readable:
  282. prefix = ['', 'Ki', 'Mi', 'Gi', 'Ti', 'Pi']
  283. dec = int(math.log(val, 2) / 10)
  284. prec = 1 if dec > 0 else 0
  285. return "{:.{prec}f}{}B".format(val / (2 ** (10 * dec)),
  286. prefix[dec], prec=prec)
  287. elif 'ops' in val_type and human_readable:
  288. prefix = ['', 'k', 'M', 'G', 'T', 'P']
  289. dec = int(math.log(val, 1000))
  290. prec = 1 if dec > 0 else 0
  291. return "{:.{prec}f}{}ops".format(val / (1000 ** dec),
  292. prefix[dec], prec=prec)
  293. return str(int(val))
  294. def sum_vals(buildstats):
  295. """Get cumulative sum of all tasks"""
  296. total = 0.0
  297. for recipe_data in buildstats.values():
  298. for bs_task in recipe_data['tasks'].values():
  299. total += sum([getattr(b, val_type) for b in bs_task]) / len(bs_task)
  300. return total
  301. tasks_diff = []
  302. if min_val:
  303. print("Ignoring tasks less than {} ({})".format(
  304. val_to_str(min_val, True), val_to_str(min_val)))
  305. if min_absdiff:
  306. print("Ignoring differences less than {} ({})".format(
  307. val_to_str(min_absdiff, True), val_to_str(min_absdiff)))
  308. # Prepare the data
  309. pkgs = set(bs1.keys()).union(set(bs2.keys()))
  310. for pkg in pkgs:
  311. tasks1 = bs1[pkg]['tasks'] if pkg in bs1 else {}
  312. tasks2 = bs2[pkg]['tasks'] if pkg in bs2 else {}
  313. if not tasks1:
  314. pkg_op = '+ '
  315. elif not tasks2:
  316. pkg_op = '- '
  317. else:
  318. pkg_op = ' '
  319. for task in set(tasks1.keys()).union(set(tasks2.keys())):
  320. task_op = ' '
  321. if task in tasks1:
  322. # Average over all values
  323. val1 = [getattr(b, val_type) for b in bs1[pkg]['tasks'][task]]
  324. val1 = sum(val1) / len(val1)
  325. else:
  326. task_op = '+ '
  327. val1 = 0
  328. if task in tasks2:
  329. # Average over all values
  330. val2 = [getattr(b, val_type) for b in bs2[pkg]['tasks'][task]]
  331. val2 = sum(val2) / len(val2)
  332. else:
  333. val2 = 0
  334. task_op = '- '
  335. if val1 == 0:
  336. reldiff = float('inf')
  337. else:
  338. reldiff = 100 * (val2 - val1) / val1
  339. if max(val1, val2) < min_val:
  340. log.debug("Filtering out %s:%s (%s)", pkg, task,
  341. val_to_str(max(val1, val2)))
  342. continue
  343. if abs(val2 - val1) < min_absdiff:
  344. log.debug("Filtering out %s:%s (difference of %s)", pkg, task,
  345. val_to_str(val2-val1))
  346. continue
  347. tasks_diff.append(TaskDiff(pkg, pkg_op, task, task_op, val1, val2,
  348. val2-val1, reldiff))
  349. # Sort our list
  350. for field in reversed(sort_by):
  351. if field.startswith('-'):
  352. field = field[1:]
  353. reverse = True
  354. else:
  355. reverse = False
  356. tasks_diff = sorted(tasks_diff, key=attrgetter(field), reverse=reverse)
  357. linedata = [(' ', 'PKG', ' ', 'TASK', 'ABSDIFF', 'RELDIFF',
  358. val_type.upper() + '1', val_type.upper() + '2')]
  359. field_lens = dict([('len_{}'.format(i), len(f)) for i, f in enumerate(linedata[0])])
  360. # Prepare fields in string format and measure field lengths
  361. for diff in tasks_diff:
  362. task_prefix = diff.task_op if diff.pkg_op == ' ' else ' '
  363. linedata.append((diff.pkg_op, diff.pkg, task_prefix, diff.task,
  364. val_to_str(diff.absdiff),
  365. '{:+.1f}%'.format(diff.reldiff),
  366. val_to_str(diff.value1),
  367. val_to_str(diff.value2)))
  368. for i, field in enumerate(linedata[-1]):
  369. key = 'len_{}'.format(i)
  370. if len(field) > field_lens[key]:
  371. field_lens[key] = len(field)
  372. # Print data
  373. print()
  374. for fields in linedata:
  375. print("{:{len_0}}{:{len_1}} {:{len_2}}{:{len_3}} {:>{len_4}} {:>{len_5}} {:>{len_6}} -> {:{len_7}}".format(
  376. *fields, **field_lens))
  377. # Print summary of the diffs
  378. total1 = sum_vals(bs1)
  379. total2 = sum_vals(bs2)
  380. print("\nCumulative {}:".format(val_type))
  381. print (" {} {:+.1f}% {} ({}) -> {} ({})".format(
  382. val_to_str(total2 - total1), 100 * (total2-total1) / total1,
  383. val_to_str(total1, True), val_to_str(total1),
  384. val_to_str(total2, True), val_to_str(total2)))
  385. def parse_args(argv):
  386. """Parse cmdline arguments"""
  387. description="""
  388. Script for comparing buildstats of two separate builds."""
  389. parser = argparse.ArgumentParser(
  390. formatter_class=argparse.ArgumentDefaultsHelpFormatter,
  391. description=description)
  392. min_val_defaults = {'cputime': 3.0,
  393. 'read_bytes': 524288,
  394. 'write_bytes': 524288,
  395. 'read_ops': 500,
  396. 'write_ops': 500,
  397. 'walltime': 5}
  398. min_absdiff_defaults = {'cputime': 1.0,
  399. 'read_bytes': 131072,
  400. 'write_bytes': 131072,
  401. 'read_ops': 50,
  402. 'write_ops': 50,
  403. 'walltime': 2}
  404. parser.add_argument('--debug', '-d', action='store_true',
  405. help="Verbose logging")
  406. parser.add_argument('--ver-diff', action='store_true',
  407. help="Show package version differences and exit")
  408. parser.add_argument('--diff-attr', default='cputime',
  409. choices=min_val_defaults.keys(),
  410. help="Buildstat attribute which to compare")
  411. parser.add_argument('--min-val', default=min_val_defaults, type=float,
  412. help="Filter out tasks less than MIN_VAL. "
  413. "Default depends on --diff-attr.")
  414. parser.add_argument('--min-absdiff', default=min_absdiff_defaults, type=float,
  415. help="Filter out tasks whose difference is less than "
  416. "MIN_ABSDIFF, Default depends on --diff-attr.")
  417. parser.add_argument('--sort-by', default='absdiff',
  418. help="Comma-separated list of field sort order. "
  419. "Prepend the field name with '-' for reversed sort. "
  420. "Available fields are: {}".format(', '.join(taskdiff_fields)))
  421. parser.add_argument('--multi', action='store_true',
  422. help="Read all buildstats from the given paths and "
  423. "average over them")
  424. parser.add_argument('buildstats1', metavar='BUILDSTATS1', help="'Left' buildstat")
  425. parser.add_argument('buildstats2', metavar='BUILDSTATS2', help="'Right' buildstat")
  426. args = parser.parse_args(argv)
  427. # We do not nedd/want to read all buildstats if we just want to look at the
  428. # package versions
  429. if args.ver_diff:
  430. args.multi = False
  431. # Handle defaults for the filter arguments
  432. if args.min_val is min_val_defaults:
  433. args.min_val = min_val_defaults[args.diff_attr]
  434. if args.min_absdiff is min_absdiff_defaults:
  435. args.min_absdiff = min_absdiff_defaults[args.diff_attr]
  436. return args
  437. def main(argv=None):
  438. """Script entry point"""
  439. args = parse_args(argv)
  440. if args.debug:
  441. log.setLevel(logging.DEBUG)
  442. # Validate sort fields
  443. sort_by = []
  444. for field in args.sort_by.split(','):
  445. if field.lstrip('-') not in taskdiff_fields:
  446. log.error("Invalid sort field '%s' (must be one of: %s)" %
  447. (field, ', '.join(taskdiff_fields)))
  448. sys.exit(1)
  449. sort_by.append(field)
  450. try:
  451. bs1 = read_buildstats(args.buildstats1, args.multi)
  452. bs2 = read_buildstats(args.buildstats2, args.multi)
  453. if args.ver_diff:
  454. print_ver_diff(bs1, bs2)
  455. else:
  456. print_task_diff(bs1, bs2, args.diff_attr, args.min_val,
  457. args.min_absdiff, sort_by)
  458. except ScriptError as err:
  459. log.error(str(err))
  460. return 1
  461. return 0
  462. if __name__ == "__main__":
  463. sys.exit(main())