Home | History | Annotate | Download | only in bootperf-bin
      1 # Copyright (c) 2010 The Chromium OS Authors. All rights reserved.
      2 # Use of this source code is governed by a BSD-style license that can be
      3 # found in the LICENSE file.
      4 
      5 """Classes and functions for managing platform_BootPerf results.
      6 
      7 Results from the platform_BootPerf test in the ChromiumOS autotest
      8 package are stored as performance 'keyvals', that is, a mapping
      9 of names to numeric values.  For each iteration of the test, one
     10 set of keyvals is recorded.
     11 
     12 This module currently tracks four kinds of keyval results: the boot
     13 time results, the disk read results, the firmware time results, and
     14 reboot time results.  These results are stored with keyval names
     15 such as 'seconds_kernel_to_login', 'rdbytes_kernel_to_login', and
     16 'seconds_power_on_to_kernel'.  These keyvals record an accumulated
     17 total measured from a fixed time in the past, e.g.
     18 'seconds_kernel_to_login' records the total seconds from kernel
     19 startup to login screen ready.
     20 
     21 The boot time keyval names all start with the prefix
     22 'seconds_kernel_to_', and record time in seconds since kernel
     23 startup.
     24 
     25 The disk read keyval names all start with the prefix
     26 'rdbytes_kernel_to_', and record bytes read from the boot device
     27 since kernel startup.
     28 
     29 The firmware keyval names all start with the prefix
     30 'seconds_power_on_to_', and record time in seconds since CPU
     31 power on.
     32 
     33 The reboot keyval names are selected from a hard-coded list of
     34 keyvals that include both some boot time and some firmware time
     35 keyvals, plus specific keyvals keyed to record shutdown and reboot
     36 time.
     37 
     38 """
     39 
     40 import math
     41 
     42 
     43 def _ListStats(list_):
     44   """Return the mean and sample standard deviation of a list.
     45 
     46   The returned result is float, even if the input list is full of
     47   integers.
     48 
     49   @param list_ The list over which to calculate.
     50 
     51   """
     52   sum_ = 0.0
     53   sumsq = 0.0
     54   for v in list_:
     55     sum_ += v
     56     sumsq += v * v
     57   n = len(list_)
     58   avg = sum_ / n
     59   var = (sumsq - sum_ * avg) / (n - 1)
     60   if var < 0.0:
     61     var = 0.0
     62   dev = math.sqrt(var)
     63   return (avg, dev)
     64 
     65 
     66 class TestResultSet(object):
     67   """A set of boot time and disk usage result statistics.
     68 
     69   Objects of this class consist of three sets of result statistics:
     70   the boot time statistics, the disk statistics, and the firmware
     71   time statistics.
     72 
     73   Class TestResultsSet does not interpret or store keyval mappings
     74   directly; iteration results are processed by attached _KeySet
     75   objects, one for each of the three types of result keyval. The
     76   _KeySet objects are kept in a dictionary; they can be obtained
     77   by calling the KeySet with the name of the keyset desired.
     78   Various methods on the KeySet objects will calculate statistics on
     79   the results, and provide the raw data.
     80 
     81   """
     82 
     83   # The names of the available KeySets, to be used as arguments to
     84   # KeySet().
     85   BOOTTIME_KEYSET = "boot"
     86   DISK_KEYSET = "disk"
     87   FIRMWARE_KEYSET = "firmware"
     88   REBOOT_KEYSET = "reboot"
     89   AVAILABLE_KEYSETS = [
     90     BOOTTIME_KEYSET, DISK_KEYSET, FIRMWARE_KEYSET, REBOOT_KEYSET
     91   ]
     92 
     93   def __init__(self, name):
     94     self.name = name
     95     self._keysets = {
     96       self.BOOTTIME_KEYSET : _TimeKeySet(),
     97       self.DISK_KEYSET : _DiskKeySet(),
     98       self.FIRMWARE_KEYSET : _FirmwareKeySet(),
     99       self.REBOOT_KEYSET : _RebootKeySet(),
    100     }
    101 
    102   def AddIterationResults(self, runkeys):
    103     """Add keyval results from a single iteration.
    104 
    105     A TestResultSet is constructed by repeatedly calling
    106     AddIterationResults(), iteration by iteration.  Iteration
    107     results are passed in as a dictionary mapping keyval attributes
    108     to values.  When all iteration results have been added,
    109     FinalizeResults() makes the results available for analysis.
    110 
    111     @param runkeys The dictionary of keyvals for the iteration.
    112 
    113     """
    114 
    115     for keyset in self._keysets.itervalues():
    116       keyset.AddIterationResults(runkeys)
    117 
    118   def FinalizeResults(self):
    119     """Make results available for analysis.
    120 
    121     A TestResultSet is constructed by repeatedly feeding it results,
    122     iteration by iteration.  Iteration results are passed in as a
    123     dictionary mapping keyval attributes to values.  When all iteration
    124     results have been added, FinalizeResults() makes the results
    125     available for analysis.
    126 
    127     """
    128 
    129     for keyset in self._keysets.itervalues():
    130       keyset.FinalizeResults()
    131 
    132   def KeySet(self, keytype):
    133     """Return a selected keyset from the test results.
    134 
    135     @param keytype Selector for the desired keyset.
    136 
    137     """
    138     return self._keysets[keytype]
    139 
    140 
    141 class _KeySet(object):
    142   """Container for a set of related statistics.
    143 
    144   _KeySet is an abstract superclass for containing collections of
    145   a related set of performance statistics.  Statistics are stored
    146   as a dictionary (`_keyvals`) mapping keyval names to lists of
    147   values.  The lists are indexed by the iteration number.
    148 
    149   The mapped keyval names are shortened by stripping the prefix
    150   that identifies the type of keyval (keyvals that don't start with
    151   the proper prefix are ignored).  So, for example, with boot time
    152   keyvals, 'seconds_kernel_to_login' becomes 'login' (and
    153   'rdbytes_kernel_to_login' is ignored).
    154 
    155   A list of all valid keyval names is stored in the `markers`
    156   instance variable.  The list is sorted by the ordering of the
    157   average of the corresponding values.  Each iteration is required
    158   to contain the same set of keyvals.  This is enforced in
    159   FinalizeResults() (see below).
    160 
    161   """
    162 
    163   def __init__(self):
    164     self._keyvals = {}
    165 
    166   def _CheckCounts(self):
    167     """Check the validity of the keyvals results dictionary.
    168 
    169     Each keyval must have occurred the same number of times.  When
    170     this check succeeds, it returns the total number of occurrences;
    171     on failure return `None`.
    172 
    173     """
    174     check = map(len, self._keyvals.values())
    175     if not check:
    176       return None
    177     for i in range(1, len(check)):
    178       if check[i] != check[i-1]:
    179         return None
    180     return check[0]
    181 
    182   def AddIterationResults(self, runkeys):
    183     """Add results for one iteration.
    184 
    185     @param runkeys The dictionary of keyvals for the iteration.
    186     """
    187     for key, value in runkeys.iteritems():
    188       if not key.startswith(self.PREFIX):
    189         continue
    190       shortkey = key[len(self.PREFIX):]
    191       keylist = self._keyvals.setdefault(shortkey, [])
    192       keylist.append(self._ConvertVal(value))
    193 
    194   def FinalizeResults(self):
    195     """Finalize this object's results.
    196 
    197     This method makes available the `markers` and `num_iterations`
    198     instance variables.  It also ensures that every keyval occurred
    199     in every iteration by requiring that all keyvals have the same
    200     number of data points.
    201 
    202     """
    203     count = self._CheckCounts()
    204     if count is None:
    205       self.num_iterations = 0
    206       self.markers = []
    207       return False
    208     self.num_iterations = count
    209     keylist = map(lambda k: (sum(self._keyvals[k]), k),
    210                   self._keyvals.keys())
    211     keylist.sort(key=lambda tp: tp[0])
    212     self.markers = map(lambda tp: tp[1], keylist)
    213     return True
    214 
    215   def RawData(self, key):
    216     """Return the list of values for the given key.
    217 
    218     @param key Key of the list of values to return.
    219 
    220     """
    221     return self._keyvals[key]
    222 
    223   def DeltaData(self, key0, key1):
    224     """Return the vector difference between two keyvals lists.
    225 
    226     @param key0 Key of the subtrahend vector.
    227     @param key1 Key of the subtractor vector.
    228 
    229     """
    230     return map(lambda a, b: b - a,
    231                self._keyvals[key0],
    232                self._keyvals[key1])
    233 
    234   def Statistics(self, key):
    235     """Return the average and standard deviation for a key.
    236 
    237     @param key
    238     """
    239     return _ListStats(self._keyvals[key])
    240 
    241   def DeltaStatistics(self, key0, key1):
    242     """Return the average and standard deviation between two keys.
    243 
    244     Calculates the difference between each matching element in the
    245     two key's lists, and returns the average and sample standard
    246     deviation of the differences.
    247 
    248     @param key0 Key of the subtrahend.
    249     @param key1 Key of the subtractor.
    250 
    251     """
    252     return _ListStats(self.DeltaData(key0, key1))
    253 
    254 
    255 class _TimeKeySet(_KeySet):
    256   """Concrete subclass of _KeySet for boot time statistics."""
    257 
    258   PREFIX = 'seconds_kernel_to_'
    259 
    260   # Time-based keyvals are reported in seconds and get converted to
    261   # milliseconds
    262   TIME_SCALE = 1000
    263 
    264   def _ConvertVal(self, value):
    265     """Return a keyval value in its 'canonical' form.
    266 
    267     For boot time values, the input is seconds as a float; the
    268     canonical form is milliseconds as an integer.
    269 
    270     @param value A time statistic in seconds.
    271 
    272     """
    273     # We want to return the nearest exact integer here.  round()
    274     # returns a float, and int() truncates its results, so we have
    275     # to combine them.
    276     return int(round(self.TIME_SCALE * float(value)))
    277 
    278   def PrintableStatistic(self, value):
    279     """Return a keyval in its preferred form for printing.
    280 
    281     The return value is a tuple of a string to be printed, and
    282     value rounded to the precision to which it was printed.
    283 
    284     Rationale: Some callers of this function total up intermediate
    285     results.  Returning the rounded value makes those totals more
    286     robust against visible rounding anomalies.
    287 
    288     @param value The value to be printed.
    289 
    290     """
    291     v = int(round(value))
    292     return ("%d" % v, v)
    293 
    294 
    295 class _FirmwareKeySet(_TimeKeySet):
    296   """Concrete subclass of _KeySet for firmware time statistics."""
    297 
    298   PREFIX = 'seconds_power_on_to_'
    299 
    300   # Time-based keyvals are reported in seconds and get converted to
    301   # milliseconds
    302   TIME_SCALE = 1000
    303 
    304 
    305 class _RebootKeySet(_TimeKeySet):
    306   """Concrete subclass of _KeySet for reboot time statistics."""
    307 
    308   PREFIX = ''
    309 
    310   # Time-based keyvals are reported in seconds and get converted to
    311   # milliseconds
    312   TIME_SCALE = 1000
    313 
    314   def AddIterationResults(self, runkeys):
    315     """Add results for one iteration.
    316 
    317     For _RebootKeySet, we cherry-pick and normalize a hard-coded
    318     list of keyvals.
    319 
    320     @param runkeys The dictionary of keyvals for the iteration.
    321     """
    322     # The time values we report are calculated as the time from when
    323     # shutdown was requested.  However, the actual keyvals from the
    324     # test are reported, variously, as "time from shutdown request",
    325     # "time from power-on", and "time from kernel start".  So,
    326     # the values have to be normalized to a common time line.
    327     #
    328     # The keyvals below capture the time from shutdown request of
    329     # the _end_ of a designated phase of reboot, as follows:
    330     #   shutdown - end of shutdown, start of firmware power-on
    331     #       sequence.
    332     #   firmware - end of firmware, transfer to kernel.
    333     #   startup - end of kernel initialization, Upstart's "startup"
    334     #       event.
    335     #   chrome_exec - session_manager initialization complete,
    336     #       Chrome starts running.
    337     #   login - Chrome completes initialization of the login screen.
    338     #
    339     shutdown = float(runkeys["seconds_shutdown_time"])
    340     firmware_time = float(runkeys["seconds_power_on_to_kernel"])
    341     startup = float(runkeys["seconds_kernel_to_startup"])
    342     chrome_exec = float(runkeys["seconds_kernel_to_chrome_exec"])
    343     reboot = float(runkeys["seconds_reboot_time"])
    344     newkeys = {}
    345     newkeys["shutdown"] = shutdown
    346     newkeys["firmware"] = shutdown + firmware_time
    347     newkeys["startup"] = newkeys["firmware"] + startup
    348     newkeys["chrome_exec"] = newkeys["firmware"] + chrome_exec
    349     newkeys["login"] = reboot
    350     super(_RebootKeySet, self).AddIterationResults(newkeys)
    351 
    352 
    353 class _DiskKeySet(_KeySet):
    354   """Concrete subclass of _KeySet for disk read statistics."""
    355 
    356   PREFIX = 'rdbytes_kernel_to_'
    357 
    358   # Disk read keyvals are reported in bytes and get converted to
    359   # MBytes (1 MByte = 1 million bytes, not 2**20)
    360   DISK_SCALE = 1.0e-6
    361 
    362   def _ConvertVal(self, value):
    363     """Return a keyval value in its 'canonical' form.
    364 
    365     For disk statistics, the input is bytes as a float; the
    366     canonical form is megabytes as a float.
    367 
    368     @param value A disk data statistic in megabytes.
    369 
    370     """
    371     return self.DISK_SCALE * float(value)
    372 
    373   def PrintableStatistic(self, value):
    374     """Return a keyval in its preferred form for printing.
    375 
    376     The return value is a tuple of a string to be printed, and
    377     value rounded to the precision to which it was printed.
    378 
    379     Rationale: Some callers of this function total up intermediate
    380     results.  Returning the rounded value makes those totals more
    381     robust against visible rounding anomalies.
    382 
    383     @param value The value to be printed.
    384 
    385     """
    386     v = round(value, 1)
    387     return ("%.1fM" % v, v)
    388