Home | History | Annotate | Download | only in binary_search_tool
      1 #!/usr/bin/env python2
      2 
      3 # Copyright 2018 The Chromium OS Authors. All rights reserved.
      4 # Use of this source code is governed by a BSD-style license that can be
      5 # found in the LICENSE file.
      6 """The binary search wrapper."""
      7 
      8 from __future__ import print_function
      9 
     10 import argparse
     11 import contextlib
     12 import errno
     13 import math
     14 import os
     15 import pickle
     16 import re
     17 import sys
     18 import tempfile
     19 import time
     20 
     21 # Adds cros_utils to PYTHONPATH
     22 import common
     23 
     24 # Now we do import from cros_utils
     25 from cros_utils import command_executer
     26 from cros_utils import logger
     27 
     28 import binary_search_perforce
     29 import pass_mapping
     30 
     31 GOOD_SET_VAR = 'BISECT_GOOD_SET'
     32 BAD_SET_VAR = 'BISECT_BAD_SET'
     33 
     34 STATE_FILE = '%s.state' % sys.argv[0]
     35 HIDDEN_STATE_FILE = os.path.join(
     36     os.path.dirname(STATE_FILE), '.%s' % os.path.basename(STATE_FILE))
     37 
     38 
     39 class Error(Exception):
     40   """The general binary search tool error class."""
     41   pass
     42 
     43 
     44 @contextlib.contextmanager
     45 def SetFile(env_var, items):
     46   """Generate set files that can be used by switch/test scripts.
     47 
     48   Generate temporary set file (good/bad) holding contents of good/bad items for
     49   the current binary search iteration. Store the name of each file as an
     50   environment variable so all child processes can access it.
     51 
     52   This function is a contextmanager, meaning it's meant to be used with the
     53   "with" statement in Python. This is so cleanup and setup happens automatically
     54   and cleanly. Execution of the outer "with" statement happens at the "yield"
     55   statement.
     56 
     57   Args:
     58     env_var: What environment variable to store the file name in.
     59     items: What items are in this set.
     60   """
     61   with tempfile.NamedTemporaryFile() as f:
     62     os.environ[env_var] = f.name
     63     f.write('\n'.join(items))
     64     f.flush()
     65     yield
     66 
     67 
     68 class BinarySearchState(object):
     69   """The binary search state class."""
     70 
     71   def __init__(self, get_initial_items, switch_to_good, switch_to_bad,
     72                test_setup_script, test_script, incremental, prune, pass_bisect,
     73                iterations, prune_iterations, verify, file_args, verbose):
     74     """BinarySearchState constructor, see Run for full args documentation."""
     75     self.get_initial_items = get_initial_items
     76     self.switch_to_good = switch_to_good
     77     self.switch_to_bad = switch_to_bad
     78     self.test_setup_script = test_setup_script
     79     self.test_script = test_script
     80     self.incremental = incremental
     81     self.prune = prune
     82     self.pass_bisect = pass_bisect
     83     self.iterations = iterations
     84     self.prune_iterations = prune_iterations
     85     self.verify = verify
     86     self.file_args = file_args
     87     self.verbose = verbose
     88 
     89     self.l = logger.GetLogger()
     90     self.ce = command_executer.GetCommandExecuter()
     91 
     92     self.resumed = False
     93     self.prune_cycles = 0
     94     self.search_cycles = 0
     95     self.binary_search = None
     96     self.all_items = None
     97     self.cmd_script = None
     98     self.mode = None
     99     self.PopulateItemsUsingCommand(self.get_initial_items)
    100     self.currently_good_items = set([])
    101     self.currently_bad_items = set([])
    102     self.found_items = set([])
    103     self.known_good = set([])
    104 
    105     self.start_time = time.time()
    106 
    107   def SwitchToGood(self, item_list):
    108     """Switch given items to "good" set."""
    109     if self.incremental:
    110       self.l.LogOutput(
    111           'Incremental set. Wanted to switch %s to good' % str(item_list),
    112           print_to_console=self.verbose)
    113       incremental_items = [
    114           item for item in item_list if item not in self.currently_good_items
    115       ]
    116       item_list = incremental_items
    117       self.l.LogOutput(
    118           'Incremental set. Actually switching %s to good' % str(item_list),
    119           print_to_console=self.verbose)
    120 
    121     if not item_list:
    122       return
    123 
    124     self.l.LogOutput(
    125         'Switching %s to good' % str(item_list), print_to_console=self.verbose)
    126     self.RunSwitchScript(self.switch_to_good, item_list)
    127     self.currently_good_items = self.currently_good_items.union(set(item_list))
    128     self.currently_bad_items.difference_update(set(item_list))
    129 
    130   def SwitchToBad(self, item_list):
    131     """Switch given items to "bad" set."""
    132     if self.incremental:
    133       self.l.LogOutput(
    134           'Incremental set. Wanted to switch %s to bad' % str(item_list),
    135           print_to_console=self.verbose)
    136       incremental_items = [
    137           item for item in item_list if item not in self.currently_bad_items
    138       ]
    139       item_list = incremental_items
    140       self.l.LogOutput(
    141           'Incremental set. Actually switching %s to bad' % str(item_list),
    142           print_to_console=self.verbose)
    143 
    144     if not item_list:
    145       return
    146 
    147     self.l.LogOutput(
    148         'Switching %s to bad' % str(item_list), print_to_console=self.verbose)
    149     self.RunSwitchScript(self.switch_to_bad, item_list)
    150     self.currently_bad_items = self.currently_bad_items.union(set(item_list))
    151     self.currently_good_items.difference_update(set(item_list))
    152 
    153   def RunSwitchScript(self, switch_script, item_list):
    154     """Pass given items to switch script.
    155 
    156     Args:
    157       switch_script: path to switch script
    158       item_list: list of all items to be switched
    159     """
    160     if self.file_args:
    161       with tempfile.NamedTemporaryFile() as f:
    162         f.write('\n'.join(item_list))
    163         f.flush()
    164         command = '%s %s' % (switch_script, f.name)
    165         ret, _, _ = self.ce.RunCommandWExceptionCleanup(
    166             command, print_to_console=self.verbose)
    167     else:
    168       command = '%s %s' % (switch_script, ' '.join(item_list))
    169       try:
    170         ret, _, _ = self.ce.RunCommandWExceptionCleanup(
    171             command, print_to_console=self.verbose)
    172       except OSError as e:
    173         if e.errno == errno.E2BIG:
    174           raise Error('Too many arguments for switch script! Use --file_args')
    175         else:
    176           raise
    177     assert ret == 0, 'Switch script %s returned %d' % (switch_script, ret)
    178 
    179   def TestScript(self):
    180     """Run test script and return exit code from script."""
    181     command = self.test_script
    182     ret, _, _ = self.ce.RunCommandWExceptionCleanup(command)
    183     return ret
    184 
    185   def TestSetupScript(self):
    186     """Run test setup script and return exit code from script."""
    187     if not self.test_setup_script:
    188       return 0
    189 
    190     command = self.test_setup_script
    191     ret, _, _ = self.ce.RunCommandWExceptionCleanup(command)
    192     return ret
    193 
    194   def GenerateBadCommandScript(self, bad_items):
    195     """Generate command line script for building bad item."""
    196     assert not self.prune, 'Prune must be false if pass_bisect is set.'
    197     assert len(bad_items) == 1, 'Pruning is off, but number of bad ' \
    198                                        'items found was not 1.'
    199     item = list(bad_items)[0]
    200     command = '%s %s' % (self.pass_bisect, item)
    201     ret, _, _ = self.ce.RunCommandWExceptionCleanup(
    202         command, print_to_console=self.verbose)
    203     return ret
    204 
    205   def DoVerify(self):
    206     """Verify correctness of test environment.
    207 
    208     Verify that a "good" set of items produces a "good" result and that a "bad"
    209     set of items produces a "bad" result. To be run directly before running
    210     DoSearch. If verify is False this step is skipped.
    211     """
    212     if not self.verify:
    213       return
    214 
    215     self.l.LogOutput('VERIFICATION')
    216     self.l.LogOutput('Beginning tests to verify good/bad sets\n')
    217 
    218     self._OutputProgress('Verifying items from GOOD set\n')
    219     with SetFile(GOOD_SET_VAR, self.all_items), SetFile(BAD_SET_VAR, []):
    220       self.l.LogOutput('Resetting all items to good to verify.')
    221       self.SwitchToGood(self.all_items)
    222       status = self.TestSetupScript()
    223       assert status == 0, 'When reset_to_good, test setup should succeed.'
    224       status = self.TestScript()
    225       assert status == 0, 'When reset_to_good, status should be 0.'
    226 
    227     self._OutputProgress('Verifying items from BAD set\n')
    228     with SetFile(GOOD_SET_VAR, []), SetFile(BAD_SET_VAR, self.all_items):
    229       self.l.LogOutput('Resetting all items to bad to verify.')
    230       self.SwitchToBad(self.all_items)
    231       status = self.TestSetupScript()
    232       # The following assumption is not true; a bad image might not
    233       # successfully push onto a device.
    234       # assert status == 0, 'When reset_to_bad, test setup should succeed.'
    235       if status == 0:
    236         status = self.TestScript()
    237       assert status == 1, 'When reset_to_bad, status should be 1.'
    238 
    239   def DoSearchBadItems(self):
    240     """Perform full search for bad items.
    241 
    242     Perform full search until prune_iterations number of bad items are found.
    243     """
    244     while (True and len(self.all_items) > 1 and
    245            self.prune_cycles < self.prune_iterations):
    246       terminated = self.DoBinarySearchBadItems()
    247       self.prune_cycles += 1
    248       if not terminated:
    249         break
    250       # Prune is set.
    251       prune_index = self.binary_search.current
    252 
    253       # If found item is last item, no new items can be found
    254       if prune_index == len(self.all_items) - 1:
    255         self.l.LogOutput('First bad item is the last item. Breaking.')
    256         self.l.LogOutput('Bad items are: %s' % self.all_items[-1])
    257         self.found_items.add(self.all_items[-1])
    258         break
    259 
    260       # If already seen item we have no new bad items to find, finish up
    261       if self.all_items[prune_index] in self.found_items:
    262         self.l.LogOutput(
    263             'Found item already found before: %s.' %
    264             self.all_items[prune_index],
    265             print_to_console=self.verbose)
    266         self.l.LogOutput('No more bad items remaining. Done searching.')
    267         self.l.LogOutput('Bad items are: %s' % ' '.join(self.found_items))
    268         break
    269 
    270       new_all_items = list(self.all_items)
    271       # Move prune item to the end of the list.
    272       new_all_items.append(new_all_items.pop(prune_index))
    273       self.found_items.add(new_all_items[-1])
    274 
    275       # Everything below newly found bad item is now known to be a good item.
    276       # Take these good items out of the equation to save time on the next
    277       # search. We save these known good items so they are still sent to the
    278       # switch_to_good script.
    279       if prune_index:
    280         self.known_good.update(new_all_items[:prune_index])
    281         new_all_items = new_all_items[prune_index:]
    282 
    283       self.l.LogOutput(
    284           'Old list: %s. New list: %s' % (str(self.all_items),
    285                                           str(new_all_items)),
    286           print_to_console=self.verbose)
    287 
    288       if not self.prune:
    289         self.l.LogOutput('Not continuning further, --prune is not set')
    290         break
    291       # FIXME: Do we need to Convert the currently good items to bad
    292       self.PopulateItemsUsingList(new_all_items)
    293 
    294     # If pass level bisecting is set, generate a script which contains command
    295     # line options to rebuild bad item.
    296     if self.pass_bisect:
    297       status = self.GenerateBadCommandScript(self.found_items)
    298       if status == 0:
    299         self.cmd_script = os.path.join(
    300             os.path.dirname(self.pass_bisect), 'cmd_script.sh')
    301         self.l.LogOutput('Command script generated at %s.' % self.cmd_script)
    302       else:
    303         raise RuntimeError('Error while generating command script.')
    304 
    305   def DoBinarySearchBadItems(self):
    306     """Perform single iteration of binary search."""
    307     # If in resume mode don't reset search_cycles
    308     if not self.resumed:
    309       self.search_cycles = 0
    310     else:
    311       self.resumed = False
    312 
    313     terminated = False
    314     while self.search_cycles < self.iterations and not terminated:
    315       self.SaveState()
    316       self.OutputIterationProgressBadItem()
    317 
    318       self.search_cycles += 1
    319       [bad_items, good_items] = self.GetNextItems()
    320 
    321       with SetFile(GOOD_SET_VAR, good_items), SetFile(BAD_SET_VAR, bad_items):
    322         # TODO: bad_items should come first.
    323         self.SwitchToGood(good_items)
    324         self.SwitchToBad(bad_items)
    325         status = self.TestSetupScript()
    326         if status == 0:
    327           status = self.TestScript()
    328         terminated = self.binary_search.SetStatus(status)
    329 
    330       if terminated:
    331         self.l.LogOutput('Terminated!', print_to_console=self.verbose)
    332     if not terminated:
    333       self.l.LogOutput('Ran out of iterations searching...')
    334     self.l.LogOutput(str(self), print_to_console=self.verbose)
    335     return terminated
    336 
    337   def CollectPassName(self, pass_info):
    338     """Mapping opt-bisect output of pass info to debugcounter name."""
    339     self.l.LogOutput('Pass info: %s' % pass_info, print_to_console=self.verbose)
    340 
    341     for desc in pass_mapping.pass_name:
    342       if desc in pass_info:
    343         return pass_mapping.pass_name[desc]
    344 
    345     # If pass not found, return None
    346     return None
    347 
    348   def BuildWithPassLimit(self, limit):
    349     """ Rebuild bad item with pass level bisect limit
    350 
    351     Run command line script generated by GenerateBadCommandScript(), with
    352     pass level limit flags.
    353 
    354     Return:
    355       pass_num: current number of the pass, or total number of passes if
    356                 limit set to -1.
    357       pass_name: The debugcounter name of current limit pass.
    358     """
    359     os.environ['LIMIT_FLAGS'] = '-mllvm -opt-bisect-limit=' + str(limit)
    360     self.l.LogOutput(
    361         'Limit flags: %s' % os.environ['LIMIT_FLAGS'],
    362         print_to_console=self.verbose)
    363     command = self.cmd_script
    364     _, _, msg = self.ce.RunCommandWOutput(command, print_to_console=False)
    365 
    366     # Massages we get will be like this:
    367     #   BISECT: running pass (9) <Pass Description> on <function> (<file>)
    368     #   BISECT: running pass (10) <Pass Description> on <module> (<file>)
    369     #   BISECT: NOT running pass (11) <Pass Description> on <SCG> (<file>)
    370     #   BISECT: NOT running pass (12) <Pass Description> on <SCG> (<file>)
    371     # We want to get the pass description of last running pass, to have
    372     # transformation level bisect on it.
    373     if 'BISECT: ' not in msg:
    374       raise RuntimeError('No bisect info printed, OptBisect may not be '
    375                          'supported by the compiler.')
    376 
    377     lines = msg.split('\n')
    378     pass_num = 0
    379     last_pass = ''
    380     for l in lines:
    381       if 'running pass' in l:
    382         # For situation of limit==-1, we want the total number of passes
    383         if limit != -1 and 'BISECT: NOT ' in l:
    384           break
    385         pass_num += 1
    386         last_pass = l
    387     if limit != -1 and pass_num != limit:
    388       raise ValueError('[Error] While building, limit number does not match.')
    389     return pass_num, self.CollectPassName(last_pass)
    390 
    391   def BuildWithTransformLimit(self, limit, pass_name=None, pass_limit=-1):
    392     """ Rebuild bad item with transformation level bisect limit
    393 
    394     Run command line script generated by GenerateBadCommandScript(), with
    395     pass level limit flags and transformation level limit flags.
    396 
    397     Args:
    398       limit: transformation level limit for bad item
    399       pass_name: name of bad pass debugcounter from pass level bisect result
    400       pass_limit: pass level limit from pass level bisect result
    401     Return: Total number of transformations if limit set to -1, else return 0.
    402     """
    403     counter_name = pass_name
    404 
    405     os.environ['LIMIT_FLAGS'] = '-mllvm -opt-bisect-limit=' + \
    406                                 str(pass_limit) + \
    407                                 ' -mllvm -debug-counter=' + counter_name + \
    408                                 '-count=' + str(limit) + \
    409                                 ' -mllvm -print-debug-counter'
    410     self.l.LogOutput(
    411         'Limit flags: %s' % os.environ['LIMIT_FLAGS'],
    412         print_to_console=self.verbose)
    413     command = self.cmd_script
    414     _, _, msg = self.ce.RunCommandWOutput(command, print_to_console=False)
    415 
    416     if 'Counters and values:' not in msg:
    417       raise RuntimeError('No bisect info printed, DebugCounter may not be '
    418                          'supported by the compiler.')
    419 
    420     # With debugcounter enabled, there will be DebugCounter counting info in
    421     # the output.
    422     lines = msg.split('\n')
    423     for l in lines:
    424       if pass_name in l:
    425         # Output of debugcounter will be like:
    426         #   instcombine-visit: {10, 0, 20}
    427         #   dce-transform: {1, 0, -1}
    428         # which indicates {Count, Skip, StopAfter}.
    429         # The last number should be the limit we set.
    430         # We want the first number as the total transformation count.
    431         # Split each line by ,|{|} and we can get l_list as:
    432         #   ['instcombine: ', '10', '0', '20', '']
    433         # and we will need the second item in it.
    434         l_list = re.split(',|{|}', l)
    435         count = int(l_list[1])
    436         if limit == -1:
    437           return count
    438     # The returned value is only useful when limit == -1, which shows total
    439     # transformation count.
    440     return 0
    441 
    442   def DoSearchBadPass(self):
    443     """Perform full search for bad pass of bad item."""
    444     logger.GetLogger().LogOutput('Starting to bisect bad pass for bad item.')
    445 
    446     # Pass level bisection
    447     self.mode = 'pass'
    448     self.binary_search = binary_search_perforce.BinarySearcherForPass(
    449         logger_to_set=self.l)
    450     self.binary_search.total, _ = self.BuildWithPassLimit(-1)
    451     logger.GetLogger().LogOutput(
    452         'Total %s number: %d' % (self.mode, self.binary_search.total))
    453 
    454     pass_index, pass_name = self.DoBinarySearchBadPass()
    455 
    456     if (not pass_name and pass_index == 0):
    457       raise ValueError('Bisecting passes cannot reproduce good result.')
    458     logger.GetLogger().LogOutput('Bad pass found: %s.' % pass_name)
    459 
    460     # Transformation level bisection.
    461     logger.GetLogger().LogOutput('Starting to bisect at transformation level.')
    462 
    463     self.mode = 'transform'
    464     self.binary_search = binary_search_perforce.BinarySearcherForPass(
    465         logger_to_set=self.l)
    466     self.binary_search.total = self.BuildWithTransformLimit(
    467         -1, pass_name, pass_index)
    468     logger.GetLogger().LogOutput(
    469         'Total %s number: %d' % (self.mode, self.binary_search.total))
    470 
    471     trans_index, _ = self.DoBinarySearchBadPass(pass_index, pass_name)
    472     if (trans_index == 0):
    473       raise ValueError('Bisecting %s cannot reproduce good result.' % pass_name)
    474     logger.GetLogger().LogOutput(
    475         'Bisection result for bad item %s:\n'
    476         'Bad pass: %s at number %d\n'
    477         'Bad transformation number: %d' % (self.found_items, pass_name,
    478                                            pass_index, trans_index))
    479 
    480   def DoBinarySearchBadPass(self, pass_index=-1, pass_name=None):
    481     """Perform single iteration of binary search at pass level
    482 
    483     Args:
    484       pass_index: Works for transformation level bisection, indicates the limit
    485         number of pass from pass level bisecting result.
    486       pass_name: Works for transformation level bisection, indicates
    487         DebugCounter name of the bad pass from pass level bisecting result.
    488     Return:
    489       index: Index of problematic pass/transformation.
    490       pass_name: Works for pass level bisection, returns DebugCounter name for
    491         bad pass.
    492     """
    493     # If in resume mode don't reset search_cycles
    494     if not self.resumed:
    495       self.search_cycles = 0
    496     else:
    497       self.resumed = False
    498 
    499     terminated = False
    500     index = 0
    501     while self.search_cycles < self.iterations and not terminated:
    502       self.SaveState()
    503       self.OutputIterationProgressBadPass()
    504 
    505       self.search_cycles += 1
    506       current = self.binary_search.GetNext()
    507 
    508       if self.mode == 'pass':
    509         index, pass_name = self.BuildWithPassLimit(current)
    510       else:
    511         self.BuildWithTransformLimit(current, pass_name, pass_index)
    512         index = current
    513 
    514       # TODO: Newly generated object should not directly replace original
    515       # one, need to put it somewhere and symbol link original one to it.
    516       # Will update cmd_script to do it.
    517 
    518       status = self.TestSetupScript()
    519       assert status == 0, 'Test setup should succeed.'
    520       status = self.TestScript()
    521       terminated = self.binary_search.SetStatus(status)
    522 
    523       if terminated:
    524         self.l.LogOutput('Terminated!', print_to_console=self.verbose)
    525     if not terminated:
    526       self.l.LogOutput('Ran out of iterations searching...')
    527     self.l.LogOutput(str(self), print_to_console=self.verbose)
    528     return index, pass_name
    529 
    530   def PopulateItemsUsingCommand(self, command):
    531     """Update all_items and binary search logic from executable.
    532 
    533     This method is mainly required for enumerating the initial list of items
    534     from the get_initial_items script.
    535 
    536     Args:
    537       command: path to executable that will enumerate items.
    538     """
    539     ce = command_executer.GetCommandExecuter()
    540     _, out, _ = ce.RunCommandWExceptionCleanup(
    541         command, return_output=True, print_to_console=self.verbose)
    542     all_items = out.split()
    543     self.PopulateItemsUsingList(all_items)
    544 
    545   def PopulateItemsUsingList(self, all_items):
    546     """Update all_items and binary searching logic from list.
    547 
    548     Args:
    549       all_items: new list of all_items
    550     """
    551     self.all_items = all_items
    552     self.binary_search = binary_search_perforce.BinarySearcher(
    553         logger_to_set=self.l)
    554     self.binary_search.SetSortedList(self.all_items)
    555 
    556   def SaveState(self):
    557     """Save state to STATE_FILE.
    558 
    559     SaveState will create a new unique, hidden state file to hold data from
    560     object. Then atomically overwrite the STATE_FILE symlink to point to the
    561     new data.
    562 
    563     Raises:
    564       Error if STATE_FILE already exists but is not a symlink.
    565     """
    566     ce, l = self.ce, self.l
    567     self.ce, self.l, self.binary_search.logger = None, None, None
    568     old_state = None
    569 
    570     _, path = tempfile.mkstemp(prefix=HIDDEN_STATE_FILE, dir='.')
    571     with open(path, 'wb') as f:
    572       pickle.dump(self, f)
    573 
    574     if os.path.exists(STATE_FILE):
    575       if os.path.islink(STATE_FILE):
    576         old_state = os.readlink(STATE_FILE)
    577       else:
    578         raise Error(('%s already exists and is not a symlink!\n'
    579                      'State file saved to %s' % (STATE_FILE, path)))
    580 
    581     # Create new link and atomically overwrite old link
    582     temp_link = '%s.link' % HIDDEN_STATE_FILE
    583     os.symlink(path, temp_link)
    584     os.rename(temp_link, STATE_FILE)
    585 
    586     if old_state:
    587       os.remove(old_state)
    588 
    589     self.ce, self.l, self.binary_search.logger = ce, l, l
    590 
    591   @classmethod
    592   def LoadState(cls):
    593     """Create BinarySearchState object from STATE_FILE."""
    594     if not os.path.isfile(STATE_FILE):
    595       return None
    596     try:
    597       bss = pickle.load(file(STATE_FILE))
    598       bss.l = logger.GetLogger()
    599       bss.ce = command_executer.GetCommandExecuter()
    600       bss.binary_search.logger = bss.l
    601       bss.start_time = time.time()
    602 
    603       # Set resumed to be True so we can enter DoBinarySearch without the method
    604       # resetting our current search_cycles to 0.
    605       bss.resumed = True
    606 
    607       # Set currently_good_items and currently_bad_items to empty so that the
    608       # first iteration after resuming will always be non-incremental. This is
    609       # just in case the environment changes, the user makes manual changes, or
    610       # a previous switch_script corrupted the environment.
    611       bss.currently_good_items = set([])
    612       bss.currently_bad_items = set([])
    613 
    614       binary_search_perforce.verbose = bss.verbose
    615       return bss
    616     except StandardError:
    617       return None
    618 
    619   def RemoveState(self):
    620     """Remove STATE_FILE and its symlinked data from file system."""
    621     if os.path.exists(STATE_FILE):
    622       if os.path.islink(STATE_FILE):
    623         real_file = os.readlink(STATE_FILE)
    624         os.remove(real_file)
    625         os.remove(STATE_FILE)
    626 
    627   def GetNextItems(self):
    628     """Get next items for binary search based on result of the last test run."""
    629     border_item = self.binary_search.GetNext()
    630     index = self.all_items.index(border_item)
    631 
    632     next_bad_items = self.all_items[:index + 1]
    633     next_good_items = self.all_items[index + 1:] + list(self.known_good)
    634 
    635     return [next_bad_items, next_good_items]
    636 
    637   def ElapsedTimeString(self):
    638     """Return h m s format of elapsed time since execution has started."""
    639     diff = int(time.time() - self.start_time)
    640     seconds = diff % 60
    641     minutes = (diff / 60) % 60
    642     hours = diff / (60 * 60)
    643 
    644     seconds = str(seconds).rjust(2)
    645     minutes = str(minutes).rjust(2)
    646     hours = str(hours).rjust(2)
    647 
    648     return '%sh %sm %ss' % (hours, minutes, seconds)
    649 
    650   def _OutputProgress(self, progress_text):
    651     """Output current progress of binary search to console and logs.
    652 
    653     Args:
    654       progress_text: The progress to display to the user.
    655     """
    656     progress = ('\n***** PROGRESS (elapsed time: %s) *****\n'
    657                 '%s'
    658                 '************************************************')
    659     progress = progress % (self.ElapsedTimeString(), progress_text)
    660     self.l.LogOutput(progress)
    661 
    662   def OutputIterationProgressBadItem(self):
    663     out = ('Search %d of estimated %d.\n'
    664            'Prune %d of max %d.\n'
    665            'Current bad items found:\n'
    666            '%s\n')
    667     out = out % (self.search_cycles + 1,
    668                  math.ceil(math.log(len(self.all_items), 2)), self.prune_cycles
    669                  + 1, self.prune_iterations, ', '.join(self.found_items))
    670     self._OutputProgress(out)
    671 
    672   def OutputIterationProgressBadPass(self):
    673     out = ('Search %d of estimated %d.\n' 'Current limit: %s\n')
    674     out = out % (self.search_cycles + 1,
    675                  math.ceil(math.log(self.binary_search.total, 2)),
    676                  self.binary_search.current)
    677     self._OutputProgress(out)
    678 
    679   def __str__(self):
    680     ret = ''
    681     ret += 'all: %s\n' % str(self.all_items)
    682     ret += 'currently_good: %s\n' % str(self.currently_good_items)
    683     ret += 'currently_bad: %s\n' % str(self.currently_bad_items)
    684     ret += str(self.binary_search)
    685     return ret
    686 
    687 
    688 class MockBinarySearchState(BinarySearchState):
    689   """Mock class for BinarySearchState."""
    690 
    691   def __init__(self, **kwargs):
    692     # Initialize all arguments to None
    693     default_kwargs = {
    694         'get_initial_items': 'echo "1"',
    695         'switch_to_good': None,
    696         'switch_to_bad': None,
    697         'test_setup_script': None,
    698         'test_script': None,
    699         'incremental': True,
    700         'prune': False,
    701         'pass_bisect': None,
    702         'iterations': 50,
    703         'prune_iterations': 100,
    704         'verify': True,
    705         'file_args': False,
    706         'verbose': False
    707     }
    708     default_kwargs.update(kwargs)
    709     super(MockBinarySearchState, self).__init__(**default_kwargs)
    710 
    711 
    712 def _CanonicalizeScript(script_name):
    713   """Return canonical path to script.
    714 
    715   Args:
    716     script_name: Relative or absolute path to script
    717 
    718   Returns:
    719     Canonicalized script path
    720   """
    721   script_name = os.path.expanduser(script_name)
    722   if not script_name.startswith('/'):
    723     return os.path.join('.', script_name)
    724 
    725 
    726 def Run(get_initial_items,
    727         switch_to_good,
    728         switch_to_bad,
    729         test_script,
    730         test_setup_script=None,
    731         iterations=50,
    732         prune=False,
    733         pass_bisect=None,
    734         noincremental=False,
    735         file_args=False,
    736         verify=True,
    737         prune_iterations=100,
    738         verbose=False,
    739         resume=False):
    740   """Run binary search tool.
    741 
    742   Equivalent to running through terminal.
    743 
    744   Args:
    745     get_initial_items: Script to enumerate all items being binary searched
    746     switch_to_good: Script that will take items as input and switch them to good
    747       set
    748     switch_to_bad: Script that will take items as input and switch them to bad
    749       set
    750     test_script: Script that will determine if the current combination of good
    751       and bad items make a "good" or "bad" result.
    752     test_setup_script: Script to do necessary setup (building, compilation,
    753       etc.) for test_script.
    754     iterations: How many binary search iterations to run before exiting.
    755     prune: If False the binary search tool will stop when the first bad item is
    756       found. Otherwise then binary search tool will continue searching until all
    757       bad items are found (or prune_iterations is reached).
    758     pass_bisect: Script that takes single bad item from POPULATE_BAD and returns
    759       the compiler command used to generate the bad item. This will turn on
    760       pass/ transformation level bisection for the bad item. Requires that
    761       'prune' be set to False, and needs support of `-opt-bisect-limit`(pass)
    762       and `-print-debug-counter`(transformation) from LLVM.
    763     noincremental: Whether to send "diffs" of good/bad items to switch scripts.
    764     file_args: If True then arguments to switch scripts will be a file name
    765       containing a newline separated list of the items to switch.
    766     verify: If True, run tests to ensure initial good/bad sets actually produce
    767       a good/bad result.
    768     prune_iterations: Max number of bad items to search for.
    769     verbose: If True will print extra debug information to user.
    770     resume: If True will resume using STATE_FILE.
    771 
    772   Returns:
    773     0 for success, error otherwise
    774   """
    775   # Notice that all the argument checks are in the Run() function rather than
    776   # in the Main() function. It is not common to do so but some wrappers are
    777   # going to call Run() directly and bypass checks in Main() function.
    778   if resume:
    779     logger.GetLogger().LogOutput('Resuming from %s' % STATE_FILE)
    780     bss = BinarySearchState.LoadState()
    781     if not bss:
    782       logger.GetLogger().LogOutput(
    783           '%s is not a valid binary_search_tool state file, cannot resume!' %
    784           STATE_FILE)
    785       return 1
    786     logger.GetLogger().LogOutput('Note: resuming from previous state, '
    787                                  'ignoring given options and loading saved '
    788                                  'options instead.')
    789   else:
    790     if not (get_initial_items and switch_to_good and switch_to_bad and
    791             test_script):
    792       logger.GetLogger().LogOutput('The following options are required: '
    793                                    '[-i, -g, -b, -t] | [-r]')
    794       return 1
    795     if pass_bisect and prune:
    796       logger.GetLogger().LogOutput('"--pass_bisect" only works when '
    797                                    '"--prune" is set to be False.')
    798       return 1
    799     switch_to_good = _CanonicalizeScript(switch_to_good)
    800     switch_to_bad = _CanonicalizeScript(switch_to_bad)
    801     if test_setup_script:
    802       test_setup_script = _CanonicalizeScript(test_setup_script)
    803     if pass_bisect:
    804       pass_bisect = _CanonicalizeScript(pass_bisect)
    805     test_script = _CanonicalizeScript(test_script)
    806     get_initial_items = _CanonicalizeScript(get_initial_items)
    807     incremental = not noincremental
    808 
    809     binary_search_perforce.verbose = verbose
    810 
    811     bss = BinarySearchState(get_initial_items, switch_to_good, switch_to_bad,
    812                             test_setup_script, test_script, incremental, prune,
    813                             pass_bisect, iterations, prune_iterations, verify,
    814                             file_args, verbose)
    815     bss.DoVerify()
    816 
    817   try:
    818     bss.DoSearchBadItems()
    819     if pass_bisect:
    820       bss.DoSearchBadPass()
    821     bss.RemoveState()
    822     logger.GetLogger().LogOutput(
    823         'Total execution time: %s' % bss.ElapsedTimeString())
    824   except Error as e:
    825     logger.GetLogger().LogError(e)
    826     return 1
    827 
    828   return 0
    829 
    830 
    831 def Main(argv):
    832   """The main function."""
    833   # Common initializations
    834 
    835   parser = argparse.ArgumentParser()
    836   common.BuildArgParser(parser)
    837   logger.GetLogger().LogOutput(' '.join(argv))
    838   options = parser.parse_args(argv)
    839 
    840   # Get dictionary of all options
    841   args = vars(options)
    842   return Run(**args)
    843 
    844 
    845 if __name__ == '__main__':
    846   sys.exit(Main(sys.argv[1:]))
    847