447 lines
16 KiB
Python
447 lines
16 KiB
Python
|
#!/usr/bin/env python3
|
||
|
|
# -*- coding: utf-8 -*-
|
||
|
|
# Copyright 2019 The Chromium OS Authors. All rights reserved.
|
||
|
|
# Use of this source code is governed by a BSD-style license that can be
|
||
|
|
# found in the LICENSE file.
|
||
|
|
|
||
|
|
"""AFDO Profile analysis tool.
|
||
|
|
|
||
|
|
This script takes a good AFDO profile, a bad AFDO profile, and an external
|
||
|
|
script which deems particular AFDO profiles as GOOD/BAD/SKIP, and an output
|
||
|
|
file as arguments. Given these pieces of information, it analyzes the profiles
|
||
|
|
to try and determine what exactly is bad about the bad profile. It does this
|
||
|
|
with three main techniques: bisecting search, range search, and rough diff-ing.
|
||
|
|
|
||
|
|
The external script communicates the 'goodness' of an AFDO profile through its
|
||
|
|
exit code. The codes known to this script are:
|
||
|
|
- 0: the AFDO profile produced a good binary
|
||
|
|
- 1: the AFDO profile produced a bad binary
|
||
|
|
- 125: no result could be determined; just try another profile
|
||
|
|
- >127: quit immediately
|
||
|
|
"""
|
||
|
|
|
||
|
|
from __future__ import division, print_function
|
||
|
|
|
||
|
|
import argparse
|
||
|
|
import json
|
||
|
|
# Pylint recommends we use "from chromite.lib import cros_logging as logging".
|
||
|
|
# Chromite specific policy message, we want to keep using the standard logging
|
||
|
|
# pylint: disable=cros-logging-import
|
||
|
|
import logging
|
||
|
|
import os
|
||
|
|
import random
|
||
|
|
import subprocess
|
||
|
|
import time
|
||
|
|
from datetime import date
|
||
|
|
from enum import IntEnum
|
||
|
|
from tempfile import mkstemp
|
||
|
|
|
||
|
|
|
||
|
|
class StatusEnum(IntEnum):
|
||
|
|
"""Enum of valid statuses returned by profile decider."""
|
||
|
|
GOOD_STATUS = 0
|
||
|
|
BAD_STATUS = 1
|
||
|
|
SKIP_STATUS = 125
|
||
|
|
PROBLEM_STATUS = 127
|
||
|
|
|
||
|
|
|
||
|
|
statuses = StatusEnum.__members__.values()
|
||
|
|
|
||
|
|
_NUM_RUNS_RANGE_SEARCH = 20 # how many times range search should run its algo
|
||
|
|
|
||
|
|
|
||
|
|
def json_to_text(json_prof):
|
||
|
|
text_profile = []
|
||
|
|
for func in json_prof:
|
||
|
|
text_profile.append(func)
|
||
|
|
text_profile.append(json_prof[func])
|
||
|
|
return ''.join(text_profile)
|
||
|
|
|
||
|
|
|
||
|
|
def text_to_json(f):
|
||
|
|
"""Performs basic parsing of an AFDO text-based profile.
|
||
|
|
|
||
|
|
This parsing expects an input file object with contents of the form generated
|
||
|
|
by bin/llvm-profdata (within an LLVM build).
|
||
|
|
"""
|
||
|
|
results = {}
|
||
|
|
curr_func = None
|
||
|
|
curr_data = []
|
||
|
|
for line in f:
|
||
|
|
if not line.startswith(' '):
|
||
|
|
if curr_func:
|
||
|
|
results[curr_func] = ''.join(curr_data)
|
||
|
|
curr_data = []
|
||
|
|
curr_func, rest = line.split(':', 1)
|
||
|
|
curr_func = curr_func.strip()
|
||
|
|
curr_data.append(':' + rest)
|
||
|
|
else:
|
||
|
|
curr_data.append(line)
|
||
|
|
|
||
|
|
if curr_func:
|
||
|
|
results[curr_func] = ''.join(curr_data)
|
||
|
|
return results
|
||
|
|
|
||
|
|
|
||
|
|
def prof_to_tmp(prof):
|
||
|
|
"""Creates (and returns) temp filename for given JSON-based AFDO profile."""
|
||
|
|
fd, temp_path = mkstemp()
|
||
|
|
text_profile = json_to_text(prof)
|
||
|
|
with open(temp_path, 'w') as f:
|
||
|
|
f.write(text_profile)
|
||
|
|
os.close(fd)
|
||
|
|
return temp_path
|
||
|
|
|
||
|
|
|
||
|
|
class DeciderState(object):
|
||
|
|
"""Class for the external decider."""
|
||
|
|
|
||
|
|
def __init__(self, state_file, external_decider, seed):
|
||
|
|
self.accumulated_results = [] # over this run of the script
|
||
|
|
self.external_decider = external_decider
|
||
|
|
self.saved_results = [] # imported from a previous run of this script
|
||
|
|
self.state_file = state_file
|
||
|
|
self.seed = seed if seed is not None else time.time()
|
||
|
|
|
||
|
|
def load_state(self):
|
||
|
|
if not os.path.exists(self.state_file):
|
||
|
|
logging.info('State file %s is empty, starting from beginning',
|
||
|
|
self.state_file)
|
||
|
|
return
|
||
|
|
|
||
|
|
with open(self.state_file, encoding='utf-8') as f:
|
||
|
|
try:
|
||
|
|
data = json.load(f)
|
||
|
|
except:
|
||
|
|
raise ValueError('Provided state file %s to resume from does not'
|
||
|
|
' contain a valid JSON.' % self.state_file)
|
||
|
|
|
||
|
|
if 'seed' not in data or 'accumulated_results' not in data:
|
||
|
|
raise ValueError('Provided state file %s to resume from does not contain'
|
||
|
|
' the correct information' % self.state_file)
|
||
|
|
|
||
|
|
self.seed = data['seed']
|
||
|
|
self.saved_results = data['accumulated_results']
|
||
|
|
logging.info('Restored state from %s...', self.state_file)
|
||
|
|
|
||
|
|
def save_state(self):
|
||
|
|
state = {'seed': self.seed, 'accumulated_results': self.accumulated_results}
|
||
|
|
tmp_file = self.state_file + '.new'
|
||
|
|
with open(tmp_file, 'w', encoding='utf-8') as f:
|
||
|
|
json.dump(state, f, indent=2)
|
||
|
|
os.rename(tmp_file, self.state_file)
|
||
|
|
logging.info('Logged state to %s...', self.state_file)
|
||
|
|
|
||
|
|
def run(self, prof, save_run=True):
|
||
|
|
"""Run the external deciding script on the given profile."""
|
||
|
|
if self.saved_results and save_run:
|
||
|
|
result = self.saved_results.pop(0)
|
||
|
|
self.accumulated_results.append(result)
|
||
|
|
self.save_state()
|
||
|
|
return StatusEnum(result)
|
||
|
|
|
||
|
|
filename = prof_to_tmp(prof)
|
||
|
|
|
||
|
|
try:
|
||
|
|
return_code = subprocess.call([self.external_decider, filename])
|
||
|
|
finally:
|
||
|
|
os.remove(filename)
|
||
|
|
|
||
|
|
if return_code in statuses:
|
||
|
|
status = StatusEnum(return_code)
|
||
|
|
if status == StatusEnum.PROBLEM_STATUS:
|
||
|
|
prof_file = prof_to_tmp(prof)
|
||
|
|
raise RuntimeError('Provided decider script returned PROBLEM_STATUS '
|
||
|
|
'when run on profile stored at %s. AFDO Profile '
|
||
|
|
'analysis aborting' % prof_file)
|
||
|
|
if save_run:
|
||
|
|
self.accumulated_results.append(status.value)
|
||
|
|
logging.info('Run %d of external script %s returned %s',
|
||
|
|
len(self.accumulated_results), self.external_decider,
|
||
|
|
status.name)
|
||
|
|
self.save_state()
|
||
|
|
return status
|
||
|
|
raise ValueError(
|
||
|
|
'Provided external script had unexpected return code %d' % return_code)
|
||
|
|
|
||
|
|
|
||
|
|
def bisect_profiles(decider, good, bad, common_funcs, lo, hi):
|
||
|
|
"""Recursive function which bisects good and bad profiles.
|
||
|
|
|
||
|
|
Args:
|
||
|
|
decider: function which, given a JSON-based AFDO profile, returns an
|
||
|
|
element of 'statuses' based on the status of the profile
|
||
|
|
good: JSON-based good AFDO profile
|
||
|
|
bad: JSON-based bad AFDO profile
|
||
|
|
common_funcs: the list of functions which have top-level profiles in both
|
||
|
|
'good' and 'bad'
|
||
|
|
lo: lower bound of range being bisected on
|
||
|
|
hi: upper bound of range being bisected on
|
||
|
|
|
||
|
|
Returns a dictionary with two keys: 'individuals' and 'ranges'.
|
||
|
|
'individuals': a list of individual functions found to make the profile BAD
|
||
|
|
'ranges': a list of lists of function names. Each list of functions is a list
|
||
|
|
such that including all of those from the bad profile makes the good
|
||
|
|
profile BAD. It may not be the smallest problematic combination, but
|
||
|
|
definitely contains a problematic combination of profiles.
|
||
|
|
"""
|
||
|
|
|
||
|
|
results = {'individuals': [], 'ranges': []}
|
||
|
|
if hi - lo <= 1:
|
||
|
|
logging.info('Found %s as a problematic function profile', common_funcs[lo])
|
||
|
|
results['individuals'].append(common_funcs[lo])
|
||
|
|
return results
|
||
|
|
|
||
|
|
mid = (lo + hi) // 2
|
||
|
|
lo_mid_prof = good.copy() # covers bad from lo:mid
|
||
|
|
mid_hi_prof = good.copy() # covers bad from mid:hi
|
||
|
|
for func in common_funcs[lo:mid]:
|
||
|
|
lo_mid_prof[func] = bad[func]
|
||
|
|
for func in common_funcs[mid:hi]:
|
||
|
|
mid_hi_prof[func] = bad[func]
|
||
|
|
|
||
|
|
lo_mid_verdict = decider.run(lo_mid_prof)
|
||
|
|
mid_hi_verdict = decider.run(mid_hi_prof)
|
||
|
|
|
||
|
|
if lo_mid_verdict == StatusEnum.BAD_STATUS:
|
||
|
|
result = bisect_profiles(decider, good, bad, common_funcs, lo, mid)
|
||
|
|
results['individuals'].extend(result['individuals'])
|
||
|
|
results['ranges'].extend(result['ranges'])
|
||
|
|
if mid_hi_verdict == StatusEnum.BAD_STATUS:
|
||
|
|
result = bisect_profiles(decider, good, bad, common_funcs, mid, hi)
|
||
|
|
results['individuals'].extend(result['individuals'])
|
||
|
|
results['ranges'].extend(result['ranges'])
|
||
|
|
|
||
|
|
# neither half is bad -> the issue is caused by several things occuring
|
||
|
|
# in conjunction, and this combination crosses 'mid'
|
||
|
|
if lo_mid_verdict == mid_hi_verdict == StatusEnum.GOOD_STATUS:
|
||
|
|
problem_range = range_search(decider, good, bad, common_funcs, lo, hi)
|
||
|
|
if problem_range:
|
||
|
|
logging.info('Found %s as a problematic combination of profiles',
|
||
|
|
str(problem_range))
|
||
|
|
results['ranges'].append(problem_range)
|
||
|
|
|
||
|
|
return results
|
||
|
|
|
||
|
|
|
||
|
|
def bisect_profiles_wrapper(decider, good, bad, perform_check=True):
|
||
|
|
"""Wrapper for recursive profile bisection."""
|
||
|
|
|
||
|
|
# Validate good and bad profiles are such, otherwise bisection reports noise
|
||
|
|
# Note that while decider is a random mock, these assertions may fail.
|
||
|
|
if perform_check:
|
||
|
|
if decider.run(good, save_run=False) != StatusEnum.GOOD_STATUS:
|
||
|
|
raise ValueError('Supplied good profile is not actually GOOD')
|
||
|
|
if decider.run(bad, save_run=False) != StatusEnum.BAD_STATUS:
|
||
|
|
raise ValueError('Supplied bad profile is not actually BAD')
|
||
|
|
|
||
|
|
common_funcs = sorted(func for func in good if func in bad)
|
||
|
|
if not common_funcs:
|
||
|
|
return {'ranges': [], 'individuals': []}
|
||
|
|
|
||
|
|
# shuffle because the results of our analysis can be quite order-dependent
|
||
|
|
# but this list has no inherent ordering. By shuffling each time, the chances
|
||
|
|
# of finding new, potentially interesting results are increased each time
|
||
|
|
# the program is run
|
||
|
|
random.shuffle(common_funcs)
|
||
|
|
results = bisect_profiles(decider, good, bad, common_funcs, 0,
|
||
|
|
len(common_funcs))
|
||
|
|
results['ranges'].sort()
|
||
|
|
results['individuals'].sort()
|
||
|
|
return results
|
||
|
|
|
||
|
|
|
||
|
|
def range_search(decider, good, bad, common_funcs, lo, hi):
|
||
|
|
"""Searches for problematic range crossing mid border.
|
||
|
|
|
||
|
|
The main inner algorithm is the following, which looks for the smallest
|
||
|
|
possible ranges with problematic combinations. It starts the upper bound at
|
||
|
|
the midpoint, and increments in halves until it gets a BAD profile.
|
||
|
|
Then, it increments the lower bound (in halves) until the resultant profile
|
||
|
|
is GOOD, and then we have a range that causes 'BAD'ness.
|
||
|
|
|
||
|
|
It does this _NUM_RUNS_RANGE_SEARCH times, and shuffles the functions being
|
||
|
|
looked at uniquely each time to try and get the smallest possible range
|
||
|
|
of functions in a reasonable timeframe.
|
||
|
|
"""
|
||
|
|
|
||
|
|
average = lambda x, y: int(round((x + y) // 2.0))
|
||
|
|
|
||
|
|
def find_upper_border(good_copy, funcs, lo, hi, last_bad_val=None):
|
||
|
|
"""Finds the upper border of problematic range."""
|
||
|
|
mid = average(lo, hi)
|
||
|
|
if mid in (lo, hi):
|
||
|
|
return last_bad_val or hi
|
||
|
|
|
||
|
|
for func in funcs[lo:mid]:
|
||
|
|
good_copy[func] = bad[func]
|
||
|
|
verdict = decider.run(good_copy)
|
||
|
|
|
||
|
|
# reset for next iteration
|
||
|
|
for func in funcs:
|
||
|
|
good_copy[func] = good[func]
|
||
|
|
|
||
|
|
if verdict == StatusEnum.BAD_STATUS:
|
||
|
|
return find_upper_border(good_copy, funcs, lo, mid, mid)
|
||
|
|
return find_upper_border(good_copy, funcs, mid, hi, last_bad_val)
|
||
|
|
|
||
|
|
def find_lower_border(good_copy, funcs, lo, hi, last_bad_val=None):
|
||
|
|
"""Finds the lower border of problematic range."""
|
||
|
|
mid = average(lo, hi)
|
||
|
|
if mid in (lo, hi):
|
||
|
|
return last_bad_val or lo
|
||
|
|
|
||
|
|
for func in funcs[lo:mid]:
|
||
|
|
good_copy[func] = good[func]
|
||
|
|
verdict = decider.run(good_copy)
|
||
|
|
|
||
|
|
# reset for next iteration
|
||
|
|
for func in funcs:
|
||
|
|
good_copy[func] = bad[func]
|
||
|
|
|
||
|
|
if verdict == StatusEnum.BAD_STATUS:
|
||
|
|
return find_lower_border(good_copy, funcs, mid, hi, lo)
|
||
|
|
return find_lower_border(good_copy, funcs, lo, mid, last_bad_val)
|
||
|
|
|
||
|
|
lo_mid_funcs = []
|
||
|
|
mid_hi_funcs = []
|
||
|
|
min_range_funcs = []
|
||
|
|
for _ in range(_NUM_RUNS_RANGE_SEARCH):
|
||
|
|
|
||
|
|
if min_range_funcs: # only examine range we've already narrowed to
|
||
|
|
random.shuffle(lo_mid_funcs)
|
||
|
|
random.shuffle(mid_hi_funcs)
|
||
|
|
else: # consider lo-mid and mid-hi separately bc must cross border
|
||
|
|
mid = (lo + hi) // 2
|
||
|
|
lo_mid_funcs = common_funcs[lo:mid]
|
||
|
|
mid_hi_funcs = common_funcs[mid:hi]
|
||
|
|
|
||
|
|
funcs = lo_mid_funcs + mid_hi_funcs
|
||
|
|
hi = len(funcs)
|
||
|
|
mid = len(lo_mid_funcs)
|
||
|
|
lo = 0
|
||
|
|
|
||
|
|
# because we need the problematic pair to pop up before we can narrow it
|
||
|
|
prof = good.copy()
|
||
|
|
for func in lo_mid_funcs:
|
||
|
|
prof[func] = bad[func]
|
||
|
|
|
||
|
|
upper_border = find_upper_border(prof, funcs, mid, hi)
|
||
|
|
for func in lo_mid_funcs + funcs[mid:upper_border]:
|
||
|
|
prof[func] = bad[func]
|
||
|
|
|
||
|
|
lower_border = find_lower_border(prof, funcs, lo, mid)
|
||
|
|
curr_range_funcs = funcs[lower_border:upper_border]
|
||
|
|
|
||
|
|
if not min_range_funcs or len(curr_range_funcs) < len(min_range_funcs):
|
||
|
|
min_range_funcs = curr_range_funcs
|
||
|
|
lo_mid_funcs = lo_mid_funcs[lo_mid_funcs.index(min_range_funcs[0]):]
|
||
|
|
mid_hi_funcs = mid_hi_funcs[:mid_hi_funcs.index(min_range_funcs[-1]) + 1]
|
||
|
|
if len(min_range_funcs) == 2:
|
||
|
|
min_range_funcs.sort()
|
||
|
|
return min_range_funcs # can't get any smaller
|
||
|
|
|
||
|
|
min_range_funcs.sort()
|
||
|
|
return min_range_funcs
|
||
|
|
|
||
|
|
|
||
|
|
def check_good_not_bad(decider, good, bad):
|
||
|
|
"""Check if bad prof becomes GOOD by adding funcs it lacks from good prof"""
|
||
|
|
bad_copy = bad.copy()
|
||
|
|
for func in good:
|
||
|
|
if func not in bad:
|
||
|
|
bad_copy[func] = good[func]
|
||
|
|
return decider.run(bad_copy) == StatusEnum.GOOD_STATUS
|
||
|
|
|
||
|
|
|
||
|
|
def check_bad_not_good(decider, good, bad):
|
||
|
|
"""Check if good prof BAD after adding funcs bad prof has that good doesnt"""
|
||
|
|
good_copy = good.copy()
|
||
|
|
for func in bad:
|
||
|
|
if func not in good:
|
||
|
|
good_copy[func] = bad[func]
|
||
|
|
return decider.run(good_copy) == StatusEnum.BAD_STATUS
|
||
|
|
|
||
|
|
|
||
|
|
def parse_args():
|
||
|
|
parser = argparse.ArgumentParser(
|
||
|
|
description=__doc__, formatter_class=argparse.RawDescriptionHelpFormatter)
|
||
|
|
parser.add_argument(
|
||
|
|
'--good_prof',
|
||
|
|
required=True,
|
||
|
|
help='Text-based "Good" profile for analysis')
|
||
|
|
parser.add_argument(
|
||
|
|
'--bad_prof', required=True, help='Text-based "Bad" profile for analysis')
|
||
|
|
parser.add_argument(
|
||
|
|
'--external_decider',
|
||
|
|
required=True,
|
||
|
|
help='External script that, given an AFDO profile, returns '
|
||
|
|
'GOOD/BAD/SKIP')
|
||
|
|
parser.add_argument(
|
||
|
|
'--analysis_output_file',
|
||
|
|
required=True,
|
||
|
|
help='File to output JSON results to')
|
||
|
|
parser.add_argument(
|
||
|
|
'--state_file',
|
||
|
|
default='%s/afdo_analysis_state.json' % os.getcwd(),
|
||
|
|
help='File path containing state to load from initially, and will be '
|
||
|
|
'overwritten with new state on each iteration')
|
||
|
|
parser.add_argument(
|
||
|
|
'--no_resume',
|
||
|
|
action='store_true',
|
||
|
|
help='If enabled, no initial state will be loaded and the program will '
|
||
|
|
'run from the beginning')
|
||
|
|
parser.add_argument(
|
||
|
|
'--remove_state_on_completion',
|
||
|
|
action='store_true',
|
||
|
|
help='If enabled, state file will be removed once profile analysis is '
|
||
|
|
'completed')
|
||
|
|
parser.add_argument(
|
||
|
|
'--seed', type=float, help='Float specifying seed for randomness')
|
||
|
|
return parser.parse_args()
|
||
|
|
|
||
|
|
|
||
|
|
def main(flags):
|
||
|
|
logging.getLogger().setLevel(logging.INFO)
|
||
|
|
if not flags.no_resume and flags.seed: # conflicting seeds
|
||
|
|
raise RuntimeError('Ambiguous seed value; do not resume from existing '
|
||
|
|
'state and also specify seed by command line flag')
|
||
|
|
|
||
|
|
decider = DeciderState(
|
||
|
|
flags.state_file, flags.external_decider, seed=flags.seed)
|
||
|
|
if not flags.no_resume:
|
||
|
|
decider.load_state()
|
||
|
|
random.seed(decider.seed)
|
||
|
|
|
||
|
|
with open(flags.good_prof) as good_f:
|
||
|
|
good_items = text_to_json(good_f)
|
||
|
|
with open(flags.bad_prof) as bad_f:
|
||
|
|
bad_items = text_to_json(bad_f)
|
||
|
|
|
||
|
|
bisect_results = bisect_profiles_wrapper(decider, good_items, bad_items)
|
||
|
|
gnb_result = check_good_not_bad(decider, good_items, bad_items)
|
||
|
|
bng_result = check_bad_not_good(decider, good_items, bad_items)
|
||
|
|
|
||
|
|
results = {
|
||
|
|
'seed': decider.seed,
|
||
|
|
'bisect_results': bisect_results,
|
||
|
|
'good_only_functions': gnb_result,
|
||
|
|
'bad_only_functions': bng_result
|
||
|
|
}
|
||
|
|
with open(flags.analysis_output_file, 'w', encoding='utf-8') as f:
|
||
|
|
json.dump(results, f, indent=2)
|
||
|
|
if flags.remove_state_on_completion:
|
||
|
|
os.remove(flags.state_file)
|
||
|
|
logging.info('Removed state file %s following completion of script...',
|
||
|
|
flags.state_file)
|
||
|
|
else:
|
||
|
|
completed_state_file = '%s.completed.%s' % (flags.state_file,
|
||
|
|
str(date.today()))
|
||
|
|
os.rename(flags.state_file, completed_state_file)
|
||
|
|
logging.info('Stored completed state file as %s...', completed_state_file)
|
||
|
|
return results
|
||
|
|
|
||
|
|
|
||
|
|
if __name__ == '__main__':
|
||
|
|
main(parse_args())
|