Home | History | Annotate | Download | only in power
      1 # Copyright (c) 2012 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 import collections, ctypes, fcntl, glob, logging, math, numpy, os, re, struct
      6 import threading, time
      7 import contextlib
      8 
      9 from autotest_lib.client.bin import utils
     10 from autotest_lib.client.common_lib import error, enum
     11 from autotest_lib.client.cros import kernel_trace
     12 
     13 BatteryDataReportType = enum.Enum('CHARGE', 'ENERGY')
     14 
     15 # battery data reported at 1e6 scale
     16 BATTERY_DATA_SCALE = 1e6
     17 # number of times to retry reading the battery in the case of bad data
     18 BATTERY_RETRY_COUNT = 3
     19 
     20 class DevStat(object):
     21     """
     22     Device power status. This class implements generic status initialization
     23     and parsing routines.
     24     """
     25 
     26     def __init__(self, fields, path=None):
     27         self.fields = fields
     28         self.path = path
     29 
     30 
     31     def reset_fields(self):
     32         """
     33         Reset all class fields to None to mark their status as unknown.
     34         """
     35         for field in self.fields.iterkeys():
     36             setattr(self, field, None)
     37 
     38 
     39     def read_val(self,  file_name, field_type):
     40         try:
     41             path = file_name
     42             if not file_name.startswith('/'):
     43                 path = os.path.join(self.path, file_name)
     44             f = open(path, 'r')
     45             out = f.readline()
     46             val = field_type(out)
     47             return val
     48 
     49         except:
     50             return field_type(0)
     51 
     52 
     53     def read_all_vals(self):
     54         for field, prop in self.fields.iteritems():
     55             if prop[0]:
     56                 val = self.read_val(prop[0], prop[1])
     57                 setattr(self, field, val)
     58 
     59 
     60 class ThermalStatACPI(DevStat):
     61     """
     62     ACPI-based thermal status.
     63 
     64     Fields:
     65     (All temperatures are in millidegrees Celsius.)
     66 
     67     str   enabled:            Whether thermal zone is enabled
     68     int   temp:               Current temperature
     69     str   type:               Thermal zone type
     70     int   num_trip_points:    Number of thermal trip points that activate
     71                                 cooling devices
     72     int   num_points_tripped: Temperature is above this many trip points
     73     str   trip_point_N_type:  Trip point #N's type
     74     int   trip_point_N_temp:  Trip point #N's temperature value
     75     int   cdevX_trip_point:   Trip point o cooling device #X (index)
     76     """
     77 
     78     MAX_TRIP_POINTS = 20
     79 
     80     thermal_fields = {
     81         'enabled':              ['enabled', str],
     82         'temp':                 ['temp', int],
     83         'type':                 ['type', str],
     84         'num_points_tripped':   ['', '']
     85         }
     86     path = '/sys/class/thermal/thermal_zone*'
     87 
     88     def __init__(self, path=None):
     89         # Browse the thermal folder for trip point fields.
     90         self.num_trip_points = 0
     91 
     92         thermal_fields = glob.glob(path + '/*')
     93         for file in thermal_fields:
     94             field = file[len(path + '/'):]
     95             if field.find('trip_point') != -1:
     96                 if field.find('temp'):
     97                     field_type = int
     98                 else:
     99                     field_type = str
    100                 self.thermal_fields[field] = [field, field_type]
    101 
    102                 # Count the number of trip points.
    103                 if field.find('_type') != -1:
    104                     self.num_trip_points += 1
    105 
    106         super(ThermalStatACPI, self).__init__(self.thermal_fields, path)
    107         self.update()
    108 
    109     def update(self):
    110         if not os.path.exists(self.path):
    111             return
    112 
    113         self.read_all_vals()
    114         self.num_points_tripped = 0
    115 
    116         for field in self.thermal_fields:
    117             if field.find('trip_point_') != -1 and field.find('_temp') != -1 \
    118                     and self.temp > self.read_val(field, int):
    119                 self.num_points_tripped += 1
    120                 logging.info('Temperature trip point #' + \
    121                             field[len('trip_point_'):field.rfind('_temp')] + \
    122                             ' tripped.')
    123 
    124 
    125 class ThermalStatHwmon(DevStat):
    126     """
    127     hwmon-based thermal status.
    128 
    129     Fields:
    130     int   <tname>_temp<num>_input: Current temperature in millidegrees Celsius
    131       where:
    132           <tname> : name of hwmon device in sysfs
    133           <num>   : number of temp as some hwmon devices have multiple
    134 
    135     """
    136     path = '/sys/class/hwmon'
    137 
    138     thermal_fields = {}
    139     def __init__(self, rootpath=None):
    140         if not rootpath:
    141             rootpath = self.path
    142         for subpath1 in glob.glob('%s/hwmon*' % rootpath):
    143             for subpath2 in ['','device/']:
    144                 gpaths = glob.glob("%s/%stemp*_input" % (subpath1, subpath2))
    145                 for gpath in gpaths:
    146                     bname = os.path.basename(gpath)
    147                     field_path = os.path.join(subpath1, subpath2, bname)
    148 
    149                     tname_path = os.path.join(os.path.dirname(gpath), "name")
    150                     tname = utils.read_one_line(tname_path)
    151 
    152                     field_key = "%s_%s" % (tname, bname)
    153                     self.thermal_fields[field_key] = [field_path, int]
    154 
    155         super(ThermalStatHwmon, self).__init__(self.thermal_fields, rootpath)
    156         self.update()
    157 
    158     def update(self):
    159         if not os.path.exists(self.path):
    160             return
    161 
    162         self.read_all_vals()
    163 
    164     def read_val(self,  file_name, field_type):
    165         try:
    166             path = os.path.join(self.path, file_name)
    167             f = open(path, 'r')
    168             out = f.readline()
    169             return field_type(out)
    170         except:
    171             return field_type(0)
    172 
    173 
    174 class ThermalStat(object):
    175     """helper class to instantiate various thermal devices."""
    176     def __init__(self):
    177         self._thermals = []
    178         self.min_temp = 999999999
    179         self.max_temp = -999999999
    180 
    181         thermal_stat_types = [(ThermalStatHwmon.path, ThermalStatHwmon),
    182                               (ThermalStatACPI.path, ThermalStatACPI)]
    183         for thermal_glob_path, thermal_type in thermal_stat_types:
    184             try:
    185                 thermal_path = glob.glob(thermal_glob_path)[0]
    186                 logging.debug('Using %s for thermal info.' % thermal_path)
    187                 self._thermals.append(thermal_type(thermal_path))
    188             except:
    189                 logging.debug('Could not find thermal path %s, skipping.' %
    190                               thermal_glob_path)
    191 
    192 
    193     def get_temps(self):
    194         """Get temperature readings.
    195 
    196         Returns:
    197             string of temperature readings.
    198         """
    199         temp_str = ''
    200         for thermal in self._thermals:
    201             thermal.update()
    202             for kname in thermal.fields:
    203                 if kname is 'temp' or kname.endswith('_input'):
    204                     val = getattr(thermal, kname)
    205                     temp_str += '%s:%d ' % (kname, val)
    206                     if val > self.max_temp:
    207                         self.max_temp = val
    208                     if val < self.min_temp:
    209                         self.min_temp = val
    210 
    211 
    212         return temp_str
    213 
    214 
    215 class BatteryStat(DevStat):
    216     """
    217     Battery status.
    218 
    219     Fields:
    220 
    221     float charge_full:        Last full capacity reached [Ah]
    222     float charge_full_design: Full capacity by design [Ah]
    223     float charge_now:         Remaining charge [Ah]
    224     float current_now:        Battery discharge rate [A]
    225     float energy:             Current battery charge [Wh]
    226     float energy_full:        Last full capacity reached [Wh]
    227     float energy_full_design: Full capacity by design [Wh]
    228     float energy_rate:        Battery discharge rate [W]
    229     float power_now:          Battery discharge rate [W]
    230     float remaining_time:     Remaining discharging time [h]
    231     float voltage_min_design: Minimum voltage by design [V]
    232     float voltage_max_design: Maximum voltage by design [V]
    233     float voltage_now:        Voltage now [V]
    234     """
    235 
    236     battery_fields = {
    237         'status':               ['status', str],
    238         'charge_full':          ['charge_full', float],
    239         'charge_full_design':   ['charge_full_design', float],
    240         'charge_now':           ['charge_now', float],
    241         'current_now':          ['current_now', float],
    242         'voltage_min_design':   ['voltage_min_design', float],
    243         'voltage_max_design':   ['voltage_max_design', float],
    244         'voltage_now':          ['voltage_now', float],
    245         'energy':               ['energy_now', float],
    246         'energy_full':          ['energy_full', float],
    247         'energy_full_design':   ['energy_full_design', float],
    248         'power_now':            ['power_now', float],
    249         'energy_rate':          ['', ''],
    250         'remaining_time':       ['', '']
    251         }
    252 
    253     def __init__(self, path=None):
    254         super(BatteryStat, self).__init__(self.battery_fields, path)
    255         self.update()
    256 
    257 
    258     def update(self):
    259         for _ in xrange(BATTERY_RETRY_COUNT):
    260             try:
    261                 self._read_battery()
    262                 return
    263             except error.TestError as e:
    264                 logging.warn(e)
    265                 for field, prop in self.battery_fields.iteritems():
    266                     logging.warn(field + ': ' + repr(getattr(self, field)))
    267                 continue
    268         raise error.TestError('Failed to read battery state')
    269 
    270 
    271     def _read_battery(self):
    272         self.read_all_vals()
    273 
    274         if self.charge_full == 0 and self.energy_full != 0:
    275             battery_type = BatteryDataReportType.ENERGY
    276         else:
    277             battery_type = BatteryDataReportType.CHARGE
    278 
    279         if self.voltage_min_design != 0:
    280             voltage_nominal = self.voltage_min_design
    281         else:
    282             voltage_nominal = self.voltage_now
    283 
    284         if voltage_nominal == 0:
    285             raise error.TestError('Failed to determine battery voltage')
    286 
    287         # Since charge data is present, calculate parameters based upon
    288         # reported charge data.
    289         if battery_type == BatteryDataReportType.CHARGE:
    290             self.charge_full = self.charge_full / BATTERY_DATA_SCALE
    291             self.charge_full_design = self.charge_full_design / \
    292                                       BATTERY_DATA_SCALE
    293             self.charge_now = self.charge_now / BATTERY_DATA_SCALE
    294 
    295             self.current_now = math.fabs(self.current_now) / \
    296                                BATTERY_DATA_SCALE
    297 
    298             self.energy =  voltage_nominal * \
    299                            self.charge_now / \
    300                            BATTERY_DATA_SCALE
    301             self.energy_full = voltage_nominal * \
    302                                self.charge_full / \
    303                                BATTERY_DATA_SCALE
    304             self.energy_full_design = voltage_nominal * \
    305                                       self.charge_full_design / \
    306                                       BATTERY_DATA_SCALE
    307 
    308         # Charge data not present, so calculate parameters based upon
    309         # reported energy data.
    310         elif battery_type == BatteryDataReportType.ENERGY:
    311             self.charge_full = self.energy_full / voltage_nominal
    312             self.charge_full_design = self.energy_full_design / \
    313                                       voltage_nominal
    314             self.charge_now = self.energy / voltage_nominal
    315 
    316             # TODO(shawnn): check if power_now can really be reported
    317             # as negative, in the same way current_now can
    318             self.current_now = math.fabs(self.power_now) / \
    319                                voltage_nominal
    320 
    321             self.energy = self.energy / BATTERY_DATA_SCALE
    322             self.energy_full = self.energy_full / BATTERY_DATA_SCALE
    323             self.energy_full_design = self.energy_full_design / \
    324                                       BATTERY_DATA_SCALE
    325 
    326         self.voltage_min_design = self.voltage_min_design / \
    327                                   BATTERY_DATA_SCALE
    328         self.voltage_max_design = self.voltage_max_design / \
    329                                   BATTERY_DATA_SCALE
    330         self.voltage_now = self.voltage_now / \
    331                            BATTERY_DATA_SCALE
    332         voltage_nominal = voltage_nominal / \
    333                           BATTERY_DATA_SCALE
    334 
    335         if self.charge_full > (self.charge_full_design * 1.5):
    336             raise error.TestError('Unreasonable charge_full value')
    337         if self.charge_now > (self.charge_full_design * 1.5):
    338             raise error.TestError('Unreasonable charge_now value')
    339 
    340         self.energy_rate =  self.voltage_now * self.current_now
    341 
    342         self.remaining_time = 0
    343         if self.current_now and self.energy_rate:
    344             self.remaining_time =  self.energy / self.energy_rate
    345 
    346 
    347 class LineStatDummy(object):
    348     """
    349     Dummy line stat for devices which don't provide power_supply related sysfs
    350     interface.
    351     """
    352     def __init__(self):
    353         self.online = True
    354 
    355 
    356     def update(self):
    357         pass
    358 
    359 class LineStat(DevStat):
    360     """
    361     Power line status.
    362 
    363     Fields:
    364 
    365     bool online:              Line power online
    366     """
    367 
    368     linepower_fields = {
    369         'is_online':             ['online', int]
    370         }
    371 
    372 
    373     def __init__(self, path=None):
    374         super(LineStat, self).__init__(self.linepower_fields, path)
    375         logging.debug("line path: %s", path)
    376         self.update()
    377 
    378 
    379     def update(self):
    380         self.read_all_vals()
    381         self.online = self.is_online == 1
    382 
    383 
    384 class SysStat(object):
    385     """
    386     System power status for a given host.
    387 
    388     Fields:
    389 
    390     battery:   A list of BatteryStat objects.
    391     linepower: A list of LineStat objects.
    392     """
    393     psu_types = ['Mains', 'USB', 'USB_ACA', 'USB_C', 'USB_CDP', 'USB_DCP',
    394                  'USB_PD', 'USB_PD_DRP', 'Unknown']
    395 
    396     def __init__(self):
    397         power_supply_path = '/sys/class/power_supply/*'
    398         self.battery = None
    399         self.linepower = []
    400         self.thermal = None
    401         self.battery_path = None
    402         self.linepower_path = []
    403 
    404         power_supplies = glob.glob(power_supply_path)
    405         for path in power_supplies:
    406             type_path = os.path.join(path,'type')
    407             if not os.path.exists(type_path):
    408                 continue
    409             power_type = utils.read_one_line(type_path)
    410             if power_type == 'Battery':
    411                 scope_path = os.path.join(path,'scope')
    412                 if (os.path.exists(scope_path) and
    413                         utils.read_one_line(scope_path) == 'Device'):
    414                     continue
    415                 self.battery_path = path
    416             elif power_type in self.psu_types:
    417                 self.linepower_path.append(path)
    418 
    419         if not self.battery_path or not self.linepower_path:
    420             logging.warning("System does not provide power sysfs interface")
    421 
    422         self.thermal = ThermalStat()
    423 
    424 
    425     def refresh(self):
    426         """
    427         Initialize device power status objects.
    428         """
    429         self.linepower = []
    430 
    431         if self.battery_path:
    432             self.battery = [ BatteryStat(self.battery_path) ]
    433 
    434         for path in self.linepower_path:
    435             self.linepower.append(LineStat(path))
    436         if not self.linepower:
    437             self.linepower = [ LineStatDummy() ]
    438 
    439         temp_str = self.thermal.get_temps()
    440         if temp_str:
    441             logging.info('Temperature reading: ' + temp_str)
    442         else:
    443             logging.error('Could not read temperature, skipping.')
    444 
    445 
    446     def on_ac(self):
    447         """
    448         Returns true if device is currently running from AC power.
    449         """
    450         on_ac = False
    451         for linepower in self.linepower:
    452             on_ac |= linepower.online
    453 
    454         # Butterfly can incorrectly report AC online for some time after
    455         # unplug. Check battery discharge state to confirm.
    456         if utils.get_board() == 'butterfly':
    457             on_ac &= (not self.battery_discharging())
    458         return on_ac
    459 
    460     def battery_discharging(self):
    461         """
    462         Returns true if battery is currently discharging.
    463         """
    464         return(self.battery[0].status.rstrip() == 'Discharging')
    465 
    466     def percent_current_charge(self):
    467         return self.battery[0].charge_now * 100 / \
    468                self.battery[0].charge_full_design
    469 
    470 
    471     def assert_battery_state(self, percent_initial_charge_min):
    472         """Check initial power configuration state is battery.
    473 
    474         Args:
    475           percent_initial_charge_min: float between 0 -> 1.00 of
    476             percentage of battery that must be remaining.
    477             None|0|False means check not performed.
    478 
    479         Raises:
    480           TestError: if one of battery assertions fails
    481         """
    482         if self.on_ac():
    483             raise error.TestError(
    484                 'Running on AC power. Please remove AC power cable.')
    485 
    486         percent_initial_charge = self.percent_current_charge()
    487 
    488         if percent_initial_charge_min and percent_initial_charge < \
    489                                           percent_initial_charge_min:
    490             raise error.TestError('Initial charge (%f) less than min (%f)'
    491                       % (percent_initial_charge, percent_initial_charge_min))
    492 
    493 
    494 def get_status():
    495     """
    496     Return a new power status object (SysStat). A new power status snapshot
    497     for a given host can be obtained by either calling this routine again and
    498     constructing a new SysStat object, or by using the refresh method of the
    499     SysStat object.
    500     """
    501     status = SysStat()
    502     status.refresh()
    503     return status
    504 
    505 
    506 class AbstractStats(object):
    507     """
    508     Common superclass for measurements of percentages per state over time.
    509 
    510     Public Attributes:
    511         incremental:  If False, stats returned are from a single
    512         _read_stats.  Otherwise, stats are from the difference between
    513         the current and last refresh.
    514     """
    515 
    516     @staticmethod
    517     def to_percent(stats):
    518         """
    519         Turns a dict with absolute time values into a dict with percentages.
    520         """
    521         total = sum(stats.itervalues())
    522         if total == 0:
    523             return {}
    524         return dict((k, v * 100.0 / total) for (k, v) in stats.iteritems())
    525 
    526 
    527     @staticmethod
    528     def do_diff(new, old):
    529         """
    530         Returns a dict with value deltas from two dicts with matching keys.
    531         """
    532         return dict((k, new[k] - old.get(k, 0)) for k in new.iterkeys())
    533 
    534 
    535     @staticmethod
    536     def format_results_percent(results, name, percent_stats):
    537         """
    538         Formats autotest result keys to format:
    539           percent_<name>_<key>_time
    540         """
    541         for key in percent_stats:
    542             results['percent_%s_%s_time' % (name, key)] = percent_stats[key]
    543 
    544 
    545     @staticmethod
    546     def format_results_wavg(results, name, wavg):
    547         """
    548         Add an autotest result keys to format: wavg_<name>
    549         """
    550         if wavg is not None:
    551             results['wavg_%s' % (name)] = wavg
    552 
    553 
    554     def __init__(self, name=None, incremental=True):
    555         if not name:
    556             error.TestFail("Need to name AbstractStats instance please.")
    557         self.name = name
    558         self.incremental = incremental
    559         self._stats = self._read_stats()
    560 
    561 
    562     def refresh(self):
    563         """
    564         Returns dict mapping state names to percentage of time spent in them.
    565         """
    566         raw_stats = result = self._read_stats()
    567         if self.incremental:
    568             result = self.do_diff(result, self._stats)
    569         self._stats = raw_stats
    570         return self.to_percent(result)
    571 
    572 
    573     def _automatic_weighted_average(self):
    574         """
    575         Turns a dict with absolute times (or percentages) into a weighted
    576         average value.
    577         """
    578         total = sum(self._stats.itervalues())
    579         if total == 0:
    580             return None
    581 
    582         return sum((float(k)*v) / total for (k, v) in self._stats.iteritems())
    583 
    584 
    585     def _supports_automatic_weighted_average(self):
    586         """
    587         Override!
    588 
    589         Returns True if stats collected can be automatically converted from
    590         percent distribution to weighted average. False otherwise.
    591         """
    592         return False
    593 
    594 
    595     def weighted_average(self):
    596         """
    597         Return weighted average calculated using the automated average method
    598         (if supported) or using a custom method defined by the stat.
    599         """
    600         if self._supports_automatic_weighted_average():
    601             return self._automatic_weighted_average()
    602 
    603         return self._weighted_avg_fn()
    604 
    605 
    606     def _weighted_avg_fn(self):
    607         """
    608         Override! Custom weighted average function.
    609 
    610         Returns weighted average as a single floating point value.
    611         """
    612         return None
    613 
    614 
    615     def _read_stats(self):
    616         """
    617         Override! Reads the raw data values that shall be measured into a dict.
    618         """
    619         raise NotImplementedError('Override _read_stats in the subclass!')
    620 
    621 
    622 class CPUFreqStats(AbstractStats):
    623     """
    624     CPU Frequency statistics
    625     """
    626 
    627     def __init__(self, start_cpu=-1, end_cpu=-1):
    628         cpufreq_stats_path = '/sys/devices/system/cpu/cpu*/cpufreq/stats/' + \
    629                              'time_in_state'
    630         intel_pstate_stats_path = '/sys/devices/system/cpu/intel_pstate/' + \
    631                              'aperf_mperf'
    632         self._file_paths = glob.glob(cpufreq_stats_path)
    633         num_cpus = len(self._file_paths)
    634         self._intel_pstate_file_paths = glob.glob(intel_pstate_stats_path)
    635         self._running_intel_pstate = False
    636         self._initial_perf = None
    637         self._current_perf = None
    638         self._max_freq = 0
    639         name = 'cpufreq'
    640         if not self._file_paths:
    641             logging.debug('time_in_state file not found')
    642             if self._intel_pstate_file_paths:
    643                 logging.debug('intel_pstate frequency stats file found')
    644                 self._running_intel_pstate = True
    645         else:
    646             if (start_cpu >= 0 and end_cpu >= 0
    647                     and not (start_cpu == 0 and end_cpu == num_cpus - 1)):
    648                 self._file_paths = self._file_paths[start_cpu : end_cpu]
    649                 name += '_' + str(start_cpu) + '_' + str(end_cpu)
    650 
    651         super(CPUFreqStats, self).__init__(name=name)
    652 
    653 
    654     def _read_stats(self):
    655         if self._running_intel_pstate:
    656             aperf = 0
    657             mperf = 0
    658 
    659             for path in self._intel_pstate_file_paths:
    660                 if not os.path.exists(path):
    661                     logging.debug('%s is not found', path)
    662                     continue
    663                 data = utils.read_file(path)
    664                 for line in data.splitlines():
    665                     pair = line.split()
    666                     # max_freq is supposed to be the same for all CPUs
    667                     # and remain constant throughout.
    668                     # So, we set the entry only once
    669                     if not self._max_freq:
    670                         self._max_freq = int(pair[0])
    671                     aperf += int(pair[1])
    672                     mperf += int(pair[2])
    673 
    674             if not self._initial_perf:
    675                 self._initial_perf = (aperf, mperf)
    676 
    677             self._current_perf = (aperf, mperf)
    678 
    679         stats = {}
    680         for path in self._file_paths:
    681             if not os.path.exists(path):
    682                 logging.debug('%s is not found', path)
    683                 continue
    684 
    685             data = utils.read_file(path)
    686             for line in data.splitlines():
    687                 pair = line.split()
    688                 freq = int(pair[0])
    689                 timeunits = int(pair[1])
    690                 if freq in stats:
    691                     stats[freq] += timeunits
    692                 else:
    693                     stats[freq] = timeunits
    694         return stats
    695 
    696 
    697     def _supports_automatic_weighted_average(self):
    698         return not self._running_intel_pstate
    699 
    700 
    701     def _weighted_avg_fn(self):
    702         if not self._running_intel_pstate:
    703             return None
    704 
    705         if self._current_perf[1] != self._initial_perf[1]:
    706             # Avg freq = max_freq * aperf_delta / mperf_delta
    707             return self._max_freq * \
    708                 float(self._current_perf[0] - self._initial_perf[0]) / \
    709                 (self._current_perf[1] - self._initial_perf[1])
    710         return 1.0
    711 
    712 
    713 class CPUIdleStats(AbstractStats):
    714     """
    715     CPU Idle statistics (refresh() will not work with incremental=False!)
    716     """
    717     # TODO (snanda): Handle changes in number of c-states due to events such
    718     # as ac <-> battery transitions.
    719     # TODO (snanda): Handle non-S0 states. Time spent in suspend states is
    720     # currently not factored out.
    721     def __init__(self, start_cpu=-1, end_cpu=-1):
    722         cpuidle_path = '/sys/devices/system/cpu/cpu*/cpuidle'
    723         self._cpus = glob.glob(cpuidle_path)
    724         num_cpus = len(self._cpus)
    725         name = 'cpuidle'
    726         if (start_cpu >= 0 and end_cpu >= 0
    727                 and not (start_cpu == 0 and end_cpu == num_cpus - 1)):
    728             self._cpus = self._cpus[start_cpu : end_cpu]
    729             name = name + '_' + str(start_cpu) + '_' + str(end_cpu)
    730         super(CPUIdleStats, self).__init__(name=name)
    731 
    732 
    733     def _read_stats(self):
    734         cpuidle_stats = collections.defaultdict(int)
    735         epoch_usecs = int(time.time() * 1000 * 1000)
    736         for cpu in self._cpus:
    737             state_path = os.path.join(cpu, 'state*')
    738             states = glob.glob(state_path)
    739             cpuidle_stats['C0'] += epoch_usecs
    740 
    741             for state in states:
    742                 name = utils.read_one_line(os.path.join(state, 'name'))
    743                 latency = utils.read_one_line(os.path.join(state, 'latency'))
    744 
    745                 if not int(latency) and name == 'POLL':
    746                     # C0 state. Kernel stats aren't right, so calculate by
    747                     # subtracting all other states from total time (using epoch
    748                     # timer since we calculate differences in the end anyway).
    749                     # NOTE: Only x86 lists C0 under cpuidle, ARM does not.
    750                     continue
    751 
    752                 usecs = int(utils.read_one_line(os.path.join(state, 'time')))
    753                 cpuidle_stats['C0'] -= usecs
    754 
    755                 if name == '<null>':
    756                     # Kernel race condition that can happen while a new C-state
    757                     # gets added (e.g. AC->battery). Don't know the 'name' of
    758                     # the state yet, but its 'time' would be 0 anyway.
    759                     logging.warning('Read name: <null>, time: %d from %s'
    760                         % (usecs, state) + '... skipping.')
    761                     continue
    762 
    763                 cpuidle_stats[name] += usecs
    764 
    765         return cpuidle_stats
    766 
    767 
    768 class CPUPackageStats(AbstractStats):
    769     """
    770     Package C-state residency statistics for modern Intel CPUs.
    771     """
    772 
    773     ATOM         =              {'C2': 0x3F8, 'C4': 0x3F9, 'C6': 0x3FA}
    774     NEHALEM      =              {'C3': 0x3F8, 'C6': 0x3F9, 'C7': 0x3FA}
    775     SANDY_BRIDGE = {'C2': 0x60D, 'C3': 0x3F8, 'C6': 0x3F9, 'C7': 0x3FA}
    776     SILVERMONT   = {'C6': 0x3FA}
    777     GOLDMONT     = {'C2': 0x60D, 'C3': 0x3F8, 'C6': 0x3F9,'C10': 0x632}
    778     BROADWELL    = {'C2': 0x60D, 'C3': 0x3F8, 'C6': 0x3F9, 'C7': 0x3FA,
    779                                  'C8': 0x630, 'C9': 0x631,'C10': 0x632}
    780 
    781     def __init__(self):
    782         def _get_platform_states():
    783             """
    784             Helper to decide what set of microarchitecture-specific MSRs to use.
    785 
    786             Returns: dict that maps C-state name to MSR address, or None.
    787             """
    788             cpu_uarch = utils.get_intel_cpu_uarch()
    789 
    790             return {
    791                 # model groups pulled from Intel SDM, volume 4
    792                 # Group same package cstate using the older uarch name
    793                 #
    794                 # TODO(harry.pan): As the keys represent microarchitecture
    795                 # names, we could consider to rename the PC state groups
    796                 # to avoid ambiguity.
    797                 'Airmont':      self.SILVERMONT,
    798                 'Atom':         self.ATOM,
    799                 'Broadwell':    self.BROADWELL,
    800                 'Goldmont':     self.GOLDMONT,
    801                 'Haswell':      self.SANDY_BRIDGE,
    802                 'Ivy Bridge':   self.SANDY_BRIDGE,
    803                 'Ivy Bridge-E': self.SANDY_BRIDGE,
    804                 'Kaby Lake':    self.BROADWELL,
    805                 'Nehalem':      self.NEHALEM,
    806                 'Sandy Bridge': self.SANDY_BRIDGE,
    807                 'Silvermont':   self.SILVERMONT,
    808                 'Skylake':      self.BROADWELL,
    809                 'Westmere':     self.NEHALEM,
    810                 }.get(cpu_uarch, None)
    811 
    812         self._platform_states = _get_platform_states()
    813         super(CPUPackageStats, self).__init__(name='cpupkg')
    814 
    815 
    816     def _read_stats(self):
    817         packages = set()
    818         template = '/sys/devices/system/cpu/cpu%s/topology/physical_package_id'
    819         if not self._platform_states:
    820             return {}
    821         stats = dict((state, 0) for state in self._platform_states)
    822         stats['C0_C1'] = 0
    823 
    824         for cpu in os.listdir('/dev/cpu'):
    825             if not os.path.exists(template % cpu):
    826                 continue
    827             package = utils.read_one_line(template % cpu)
    828             if package in packages:
    829                 continue
    830             packages.add(package)
    831 
    832             stats['C0_C1'] += utils.rdmsr(0x10, cpu) # TSC
    833             for (state, msr) in self._platform_states.iteritems():
    834                 ticks = utils.rdmsr(msr, cpu)
    835                 stats[state] += ticks
    836                 stats['C0_C1'] -= ticks
    837 
    838         return stats
    839 
    840 
    841 class DevFreqStats(AbstractStats):
    842     """
    843     Devfreq device frequency stats.
    844     """
    845 
    846     _DIR = '/sys/class/devfreq'
    847 
    848 
    849     def __init__(self, f):
    850         """Constructs DevFreqStats Object that track frequency stats
    851         for the path of the given Devfreq device.
    852 
    853         The frequencies for devfreq devices are listed in Hz.
    854 
    855         Args:
    856             path: the path to the devfreq device
    857 
    858         Example:
    859             /sys/class/devfreq/dmc
    860         """
    861         self._path = os.path.join(self._DIR, f)
    862         if not os.path.exists(self._path):
    863             raise error.TestError('DevFreqStats: devfreq device does not exist')
    864 
    865         fname = os.path.join(self._path, 'available_frequencies')
    866         af = utils.read_one_line(fname).strip()
    867         self._available_freqs = sorted(af.split(), key=int)
    868 
    869         super(DevFreqStats, self).__init__(name=f)
    870 
    871     def _read_stats(self):
    872         stats = dict((freq, 0) for freq in self._available_freqs)
    873         fname = os.path.join(self._path, 'trans_stat')
    874 
    875         with open(fname) as fd:
    876             # The lines that contain the time in each frequency start on the 3rd
    877             # line, so skip the first 2 lines. The last line contains the number
    878             # of transitions, so skip that line too.
    879             # The time in each frequency is at the end of the line.
    880             freq_pattern = re.compile(r'\d+(?=:)')
    881             for line in fd.readlines()[2:-1]:
    882                 freq = freq_pattern.search(line)
    883                 if freq and freq.group() in self._available_freqs:
    884                     stats[freq.group()] = int(line.strip().split()[-1])
    885 
    886         return stats
    887 
    888 
    889 class GPUFreqStats(AbstractStats):
    890     """GPU Frequency statistics class.
    891 
    892     TODO(tbroch): add stats for other GPUs
    893     """
    894 
    895     _MALI_DEV = '/sys/class/misc/mali0/device'
    896     _MALI_EVENTS = ['mali_dvfs:mali_dvfs_set_clock']
    897     _MALI_TRACE_CLK_RE = r'(\d+.\d+): mali_dvfs_set_clock: frequency=(\d+)\d{6}'
    898 
    899     _I915_ROOT = '/sys/kernel/debug/dri/0'
    900     _I915_EVENTS = ['i915:intel_gpu_freq_change']
    901     _I915_CLK = os.path.join(_I915_ROOT, 'i915_cur_delayinfo')
    902     _I915_TRACE_CLK_RE = r'(\d+.\d+): intel_gpu_freq_change: new_freq=(\d+)'
    903     _I915_CUR_FREQ_RE = r'CAGF:\s+(\d+)MHz'
    904     _I915_MIN_FREQ_RE = r'Lowest \(RPN\) frequency:\s+(\d+)MHz'
    905     _I915_MAX_FREQ_RE = r'Max non-overclocked \(RP0\) frequency:\s+(\d+)MHz'
    906     # TODO(dbasehore) parse this from debugfs if/when this value is added
    907     _I915_FREQ_STEP = 50
    908 
    909     _gpu_type = None
    910 
    911 
    912     def _get_mali_freqs(self):
    913         """Get mali clocks based on kernel version.
    914 
    915         For 3.8-3.18:
    916             # cat /sys/class/misc/mali0/device/clock
    917             100000000
    918             # cat /sys/class/misc/mali0/device/available_frequencies
    919             100000000
    920             160000000
    921             266000000
    922             350000000
    923             400000000
    924             450000000
    925             533000000
    926             533000000
    927 
    928         For 4.4+:
    929             Tracked in DevFreqStats
    930 
    931         Returns:
    932           cur_mhz: string of current GPU clock in mhz
    933         """
    934         cur_mhz = None
    935         fqs = []
    936 
    937         fname = os.path.join(self._MALI_DEV, 'clock')
    938         if os.path.exists(fname):
    939             cur_mhz = str(int(int(utils.read_one_line(fname).strip()) / 1e6))
    940             fname = os.path.join(self._MALI_DEV, 'available_frequencies')
    941             with open(fname) as fd:
    942                 for ln in fd.readlines():
    943                     freq = int(int(ln.strip()) / 1e6)
    944                     fqs.append(str(freq))
    945                 fqs.sort()
    946 
    947         self._freqs = fqs
    948         return cur_mhz
    949 
    950 
    951     def __init__(self, incremental=False):
    952 
    953 
    954         min_mhz = None
    955         max_mhz = None
    956         cur_mhz = None
    957         events = None
    958         self._freqs = []
    959         self._prev_sample = None
    960         self._trace = None
    961 
    962         if os.path.exists(self._MALI_DEV) and \
    963            not os.path.exists(os.path.join(self._MALI_DEV, "devfreq")):
    964             self._set_gpu_type('mali')
    965         elif os.path.exists(self._I915_CLK):
    966             self._set_gpu_type('i915')
    967         else:
    968             # We either don't know how to track GPU stats (yet) or the stats are
    969             # tracked in DevFreqStats.
    970             self._set_gpu_type(None)
    971 
    972         logging.debug("gpu_type is %s", self._gpu_type)
    973 
    974         if self._gpu_type is 'mali':
    975             events = self._MALI_EVENTS
    976             cur_mhz = self._get_mali_freqs()
    977             if self._freqs:
    978                 min_mhz = self._freqs[0]
    979                 max_mhz = self._freqs[-1]
    980 
    981         elif self._gpu_type is 'i915':
    982             events = self._I915_EVENTS
    983             with open(self._I915_CLK) as fd:
    984                 for ln in fd.readlines():
    985                     logging.debug("ln = %s", ln)
    986                     result = re.findall(self._I915_CUR_FREQ_RE, ln)
    987                     if result:
    988                         cur_mhz = result[0]
    989                         continue
    990                     result = re.findall(self._I915_MIN_FREQ_RE, ln)
    991                     if result:
    992                         min_mhz = result[0]
    993                         continue
    994                     result = re.findall(self._I915_MAX_FREQ_RE, ln)
    995                     if result:
    996                         max_mhz = result[0]
    997                         continue
    998                 if min_mhz and max_mhz:
    999                     for i in xrange(int(min_mhz), int(max_mhz) +
   1000                                     self._I915_FREQ_STEP, self._I915_FREQ_STEP):
   1001                         self._freqs.append(str(i))
   1002 
   1003         logging.debug("cur_mhz = %s, min_mhz = %s, max_mhz = %s", cur_mhz,
   1004                       min_mhz, max_mhz)
   1005 
   1006         if cur_mhz and min_mhz and max_mhz:
   1007             self._trace = kernel_trace.KernelTrace(events=events)
   1008 
   1009         # Not all platforms or kernel versions support tracing.
   1010         if not self._trace or not self._trace.is_tracing():
   1011             logging.warning("GPU frequency tracing not enabled.")
   1012         else:
   1013             self._prev_sample = (cur_mhz, self._trace.uptime_secs())
   1014             logging.debug("Current GPU freq: %s", cur_mhz)
   1015             logging.debug("All GPU freqs: %s", self._freqs)
   1016 
   1017         super(GPUFreqStats, self).__init__(name='gpu', incremental=incremental)
   1018 
   1019 
   1020     @classmethod
   1021     def _set_gpu_type(cls, gpu_type):
   1022         cls._gpu_type = gpu_type
   1023 
   1024 
   1025     def _read_stats(self):
   1026         if self._gpu_type:
   1027             return getattr(self, "_%s_read_stats" % self._gpu_type)()
   1028         return {}
   1029 
   1030 
   1031     def _trace_read_stats(self, regexp):
   1032         """Read GPU stats from kernel trace outputs.
   1033 
   1034         Args:
   1035             regexp: regular expression to match trace output for frequency
   1036 
   1037         Returns:
   1038             Dict with key string in mhz and val float in seconds.
   1039         """
   1040         if not self._prev_sample:
   1041             return {}
   1042 
   1043         stats = dict((k, 0.0) for k in self._freqs)
   1044         results = self._trace.read(regexp=regexp)
   1045         for (tstamp_str, freq) in results:
   1046             tstamp = float(tstamp_str)
   1047 
   1048             # do not reparse lines in trace buffer
   1049             if tstamp <= self._prev_sample[1]:
   1050                 continue
   1051             delta = tstamp - self._prev_sample[1]
   1052             logging.debug("freq:%s tstamp:%f - %f delta:%f",
   1053                           self._prev_sample[0],
   1054                           tstamp, self._prev_sample[1],
   1055                           delta)
   1056             stats[self._prev_sample[0]] += delta
   1057             self._prev_sample = (freq, tstamp)
   1058 
   1059         # Do last record
   1060         delta = self._trace.uptime_secs() - self._prev_sample[1]
   1061         logging.debug("freq:%s tstamp:uptime - %f delta:%f",
   1062                       self._prev_sample[0],
   1063                       self._prev_sample[1], delta)
   1064         stats[self._prev_sample[0]] += delta
   1065 
   1066         logging.debug("GPU freq percents:%s", stats)
   1067         return stats
   1068 
   1069 
   1070     def _mali_read_stats(self):
   1071         """Read Mali GPU stats
   1072 
   1073         Frequencies are reported in Hz, so use a regex that drops the last 6
   1074         digits.
   1075 
   1076         Output in trace looks like this:
   1077 
   1078             kworker/u:24-5220  [000] .... 81060.329232: mali_dvfs_set_clock: frequency=400
   1079             kworker/u:24-5220  [000] .... 81061.830128: mali_dvfs_set_clock: frequency=350
   1080 
   1081         Returns:
   1082             Dict with frequency in mhz as key and float in seconds for time
   1083               spent at that frequency.
   1084         """
   1085         return self._trace_read_stats(self._MALI_TRACE_CLK_RE)
   1086 
   1087 
   1088     def _i915_read_stats(self):
   1089         """Read i915 GPU stats.
   1090 
   1091         Output looks like this (kernel >= 3.8):
   1092 
   1093           kworker/u:0-28247 [000] .... 259391.579610: intel_gpu_freq_change: new_freq=400
   1094           kworker/u:0-28247 [000] .... 259391.581797: intel_gpu_freq_change: new_freq=350
   1095 
   1096         Returns:
   1097             Dict with frequency in mhz as key and float in seconds for time
   1098               spent at that frequency.
   1099         """
   1100         return self._trace_read_stats(self._I915_TRACE_CLK_RE)
   1101 
   1102 
   1103 class USBSuspendStats(AbstractStats):
   1104     """
   1105     USB active/suspend statistics (over all devices)
   1106     """
   1107     # TODO (snanda): handle hot (un)plugging of USB devices
   1108     # TODO (snanda): handle duration counters wraparound
   1109 
   1110     def __init__(self):
   1111         usb_stats_path = '/sys/bus/usb/devices/*/power'
   1112         self._file_paths = glob.glob(usb_stats_path)
   1113         if not self._file_paths:
   1114             logging.debug('USB stats path not found')
   1115         super(USBSuspendStats, self).__init__(name='usb')
   1116 
   1117 
   1118     def _read_stats(self):
   1119         usb_stats = {'active': 0, 'suspended': 0}
   1120 
   1121         for path in self._file_paths:
   1122             active_duration_path = os.path.join(path, 'active_duration')
   1123             total_duration_path = os.path.join(path, 'connected_duration')
   1124 
   1125             if not os.path.exists(active_duration_path) or \
   1126                not os.path.exists(total_duration_path):
   1127                 logging.debug('duration paths do not exist for: %s', path)
   1128                 continue
   1129 
   1130             active = int(utils.read_file(active_duration_path))
   1131             total = int(utils.read_file(total_duration_path))
   1132             logging.debug('device %s active for %.2f%%',
   1133                           path, active * 100.0 / total)
   1134 
   1135             usb_stats['active'] += active
   1136             usb_stats['suspended'] += total - active
   1137 
   1138         return usb_stats
   1139 
   1140 
   1141 def get_cpu_sibling_groups():
   1142     """
   1143     Get CPU core groups in HMP systems.
   1144 
   1145     In systems with both small core and big core,
   1146     returns groups of small and big sibling groups.
   1147     """
   1148     siblings_paths = '/sys/devices/system/cpu/cpu*/topology/' + \
   1149                     'core_siblings_list'
   1150     sibling_groups = []
   1151     sibling_file_paths = glob.glob(siblings_paths)
   1152     if not len(sibling_file_paths) > 0:
   1153         return sibling_groups;
   1154     total_cpus = len(sibling_file_paths)
   1155     i = 0
   1156     sibling_list_pattern = re.compile('(\d+)-(\d+)')
   1157     while (i <  total_cpus):
   1158         siblings_data = utils.read_file(sibling_file_paths[i])
   1159         sibling_match = sibling_list_pattern.match(siblings_data)
   1160         sibling_start, sibling_end = (int(x) for x in sibling_match.groups())
   1161         sibling_groups.append((sibling_start, sibling_end))
   1162         i = sibling_end + 1
   1163     return sibling_groups
   1164 
   1165 
   1166 
   1167 class StatoMatic(object):
   1168     """Class to aggregate and monitor a bunch of power related statistics."""
   1169     def __init__(self):
   1170         self._start_uptime_secs = kernel_trace.KernelTrace.uptime_secs()
   1171         self._astats = [USBSuspendStats(),
   1172                         GPUFreqStats(incremental=False),
   1173                         CPUPackageStats()]
   1174         cpu_sibling_groups = get_cpu_sibling_groups()
   1175         if not len(cpu_sibling_groups):
   1176             self._astats.append(CPUFreqStats())
   1177             self._astats.append(CPUIdleStats())
   1178         for cpu_start, cpu_end in cpu_sibling_groups:
   1179             self._astats.append(CPUFreqStats(cpu_start, cpu_end))
   1180             self._astats.append(CPUIdleStats(cpu_start, cpu_end))
   1181         if os.path.isdir(DevFreqStats._DIR):
   1182             self._astats.extend([DevFreqStats(f) for f in \
   1183                                  os.listdir(DevFreqStats._DIR)])
   1184 
   1185         self._disk = DiskStateLogger()
   1186         self._disk.start()
   1187 
   1188 
   1189     def publish(self):
   1190         """Publishes results of various statistics gathered.
   1191 
   1192         Returns:
   1193             dict with
   1194               key = string 'percent_<name>_<key>_time'
   1195               value = float in percent
   1196         """
   1197         results = {}
   1198         tot_secs = kernel_trace.KernelTrace.uptime_secs() - \
   1199             self._start_uptime_secs
   1200         for stat_obj in self._astats:
   1201             percent_stats = stat_obj.refresh()
   1202             logging.debug("pstats = %s", percent_stats)
   1203             if stat_obj.name is 'gpu':
   1204                 # TODO(tbroch) remove this once GPU freq stats have proved
   1205                 # reliable
   1206                 stats_secs = sum(stat_obj._stats.itervalues())
   1207                 if stats_secs < (tot_secs * 0.9) or \
   1208                         stats_secs > (tot_secs * 1.1):
   1209                     logging.warning('%s stats dont look right.  Not publishing.',
   1210                                  stat_obj.name)
   1211                     continue
   1212             new_res = {}
   1213             AbstractStats.format_results_percent(new_res, stat_obj.name,
   1214                                                  percent_stats)
   1215             wavg = stat_obj.weighted_average()
   1216             if wavg:
   1217                 AbstractStats.format_results_wavg(new_res, stat_obj.name, wavg)
   1218 
   1219             results.update(new_res)
   1220 
   1221         new_res = {}
   1222         if self._disk.get_error():
   1223             new_res['disk_logging_error'] = str(self._disk.get_error())
   1224         else:
   1225             AbstractStats.format_results_percent(new_res, 'disk',
   1226                                                  self._disk.result())
   1227         results.update(new_res)
   1228 
   1229         return results
   1230 
   1231 
   1232 class PowerMeasurement(object):
   1233     """Class to measure power.
   1234 
   1235     Public attributes:
   1236         domain: String name of the power domain being measured.  Example is
   1237           'system' for total system power
   1238 
   1239     Public methods:
   1240         refresh: Performs any power/energy sampling and calculation and returns
   1241             power as float in watts.  This method MUST be implemented in
   1242             subclass.
   1243     """
   1244 
   1245     def __init__(self, domain):
   1246         """Constructor."""
   1247         self.domain = domain
   1248 
   1249 
   1250     def refresh(self):
   1251         """Performs any power/energy sampling and calculation.
   1252 
   1253         MUST be implemented in subclass
   1254 
   1255         Returns:
   1256             float, power in watts.
   1257         """
   1258         raise NotImplementedError("'refresh' method should be implemented in "
   1259                                   "subclass.")
   1260 
   1261 
   1262 def parse_power_supply_info():
   1263     """Parses power_supply_info command output.
   1264 
   1265     Command output from power_manager ( tools/power_supply_info.cc ) looks like
   1266     this:
   1267 
   1268         Device: Line Power
   1269           path:               /sys/class/power_supply/cros_ec-charger
   1270           ...
   1271         Device: Battery
   1272           path:               /sys/class/power_supply/sbs-9-000b
   1273           ...
   1274 
   1275     """
   1276     rv = collections.defaultdict(dict)
   1277     dev = None
   1278     for ln in utils.system_output('power_supply_info').splitlines():
   1279         logging.debug("psu: %s", ln)
   1280         result = re.findall(r'^Device:\s+(.*)', ln)
   1281         if result:
   1282             dev = result[0]
   1283             continue
   1284         result = re.findall(r'\s+(.+):\s+(.+)', ln)
   1285         if result and dev:
   1286             kname = re.findall(r'(.*)\s+\(\w+\)', result[0][0])
   1287             if kname:
   1288                 rv[dev][kname[0]] = result[0][1]
   1289             else:
   1290                 rv[dev][result[0][0]] = result[0][1]
   1291 
   1292     return rv
   1293 
   1294 
   1295 class SystemPower(PowerMeasurement):
   1296     """Class to measure system power.
   1297 
   1298     TODO(tbroch): This class provides a subset of functionality in BatteryStat
   1299     in hopes of minimizing power draw.  Investigate whether its really
   1300     significant and if not, deprecate.
   1301 
   1302     Private Attributes:
   1303       _voltage_file: path to retrieve voltage in uvolts
   1304       _current_file: path to retrieve current in uamps
   1305     """
   1306 
   1307     def __init__(self, battery_dir):
   1308         """Constructor.
   1309 
   1310         Args:
   1311             battery_dir: path to dir containing the files to probe and log.
   1312                 usually something like /sys/class/power_supply/BAT0/
   1313         """
   1314         super(SystemPower, self).__init__('system')
   1315         # Files to log voltage and current from
   1316         self._voltage_file = os.path.join(battery_dir, 'voltage_now')
   1317         self._current_file = os.path.join(battery_dir, 'current_now')
   1318 
   1319 
   1320     def refresh(self):
   1321         """refresh method.
   1322 
   1323         See superclass PowerMeasurement for details.
   1324         """
   1325         keyvals = parse_power_supply_info()
   1326         return float(keyvals['Battery']['energy rate'])
   1327 
   1328 
   1329 class MeasurementLogger(threading.Thread):
   1330     """A thread that logs measurement readings.
   1331 
   1332     Example code snippet:
   1333          mylogger = MeasurementLogger([Measurent1, Measurent2])
   1334          mylogger.run()
   1335          for testname in tests:
   1336              with my_logger.checkblock(testname):
   1337                 #run the test method for testname
   1338          keyvals = mylogger.calc()
   1339 
   1340     or
   1341          mylogger = MeasurementLogger([Measurent1, Measurent2])
   1342          mylogger.run()
   1343          for testname in tests:
   1344              start_time = time.time()
   1345              #run the test method for testname
   1346              mlogger.checkpoint(testname, start_time)
   1347          keyvals = mylogger.calc()
   1348 
   1349     Public attributes:
   1350         seconds_period: float, probing interval in seconds.
   1351         readings: list of lists of floats of measurements.
   1352         times: list of floats of time (since Epoch) of when measurements
   1353             occurred.  len(time) == len(readings).
   1354         done: flag to stop the logger.
   1355         domains: list of  domain strings being measured
   1356 
   1357     Public methods:
   1358         run: launches the thread to gather measuremnts
   1359         calc: calculates
   1360         save_results:
   1361 
   1362     Private attributes:
   1363        _measurements: list of Measurement objects to be sampled.
   1364        _checkpoint_data: list of tuples.  Tuple contains:
   1365            tname: String of testname associated with this time interval
   1366            tstart: Float of time when subtest started
   1367            tend: Float of time when subtest ended
   1368        _results: list of results tuples.  Tuple contains:
   1369            prefix: String of subtest
   1370            mean: Float of mean  in watts
   1371            std: Float of standard deviation of measurements
   1372            tstart: Float of time when subtest started
   1373            tend: Float of time when subtest ended
   1374     """
   1375     def __init__(self, measurements, seconds_period=1.0):
   1376         """Initialize a logger.
   1377 
   1378         Args:
   1379             _measurements: list of Measurement objects to be sampled.
   1380             seconds_period: float, probing interval in seconds.  Default 1.0
   1381         """
   1382         threading.Thread.__init__(self)
   1383 
   1384         self.seconds_period = seconds_period
   1385 
   1386         self.readings = []
   1387         self.times = []
   1388         self._checkpoint_data = []
   1389 
   1390         self.domains = []
   1391         self._measurements = measurements
   1392         for meas in self._measurements:
   1393             self.domains.append(meas.domain)
   1394 
   1395         self.done = False
   1396 
   1397 
   1398     def run(self):
   1399         """Threads run method."""
   1400         loop = 0
   1401         start_time = time.time()
   1402         while(not self.done):
   1403             readings = []
   1404             for meas in self._measurements:
   1405                 readings.append(meas.refresh())
   1406             # TODO (dbasehore): We probably need proper locking in this file
   1407             # since there have been race conditions with modifying and accessing
   1408             # data.
   1409             self.readings.append(readings)
   1410             current_time = time.time()
   1411             self.times.append(current_time)
   1412             loop += 1
   1413             next_measurement_time = start_time + loop * self.seconds_period
   1414             time.sleep(next_measurement_time - current_time)
   1415 
   1416     @contextlib.contextmanager
   1417     def checkblock(self, tname=''):
   1418         """Check point for the following block with test tname.
   1419 
   1420         Args:
   1421             tname: String of testname associated with this time interval
   1422         """
   1423         start_time = time.time()
   1424         yield
   1425         self.checkpoint(tname, start_time)
   1426 
   1427     def checkpoint(self, tname='', tstart=None, tend=None):
   1428         """Check point the times in seconds associated with test tname.
   1429 
   1430         Args:
   1431            tname: String of testname associated with this time interval
   1432            tstart: Float in seconds of when tname test started.  Should be based
   1433                 off time.time()
   1434            tend: Float in seconds of when tname test ended.  Should be based
   1435                 off time.time().  If None, then value computed in the method.
   1436         """
   1437         if not tstart and self.times:
   1438             tstart = self.times[0]
   1439         if not tend:
   1440             tend = time.time()
   1441         self._checkpoint_data.append((tname, tstart, tend))
   1442         logging.info('Finished test "%s" between timestamps [%s, %s]',
   1443                      tname, tstart, tend)
   1444 
   1445 
   1446     def calc(self, mtype=None):
   1447         """Calculate average measurement during each of the sub-tests.
   1448 
   1449         Method performs the following steps:
   1450             1. Signals the thread to stop running.
   1451             2. Calculates mean, max, min, count on the samples for each of the
   1452                measurements.
   1453             3. Stores results to be written later.
   1454             4. Creates keyvals for autotest publishing.
   1455 
   1456         Args:
   1457             mtype: string of measurement type.  For example:
   1458                    pwr == power
   1459                    temp == temperature
   1460         Returns:
   1461             dict of keyvals suitable for autotest results.
   1462         """
   1463         if not mtype:
   1464             mtype = 'meas'
   1465 
   1466         t = numpy.array(self.times)
   1467         keyvals = {}
   1468         results  = []
   1469 
   1470         if not self.done:
   1471             self.done = True
   1472         # times 2 the sleep time in order to allow for readings as well.
   1473         self.join(timeout=self.seconds_period * 2)
   1474 
   1475         if not self._checkpoint_data:
   1476             self.checkpoint()
   1477 
   1478         for i, domain_readings in enumerate(zip(*self.readings)):
   1479             meas = numpy.array(domain_readings)
   1480             domain = self.domains[i]
   1481 
   1482             for tname, tstart, tend in self._checkpoint_data:
   1483                 if tname:
   1484                     prefix = '%s_%s' % (tname, domain)
   1485                 else:
   1486                     prefix = domain
   1487                 keyvals[prefix+'_duration'] = tend - tstart
   1488                 # Select all readings taken between tstart and tend timestamps.
   1489                 # Try block just in case
   1490                 # code.google.com/p/chromium/issues/detail?id=318892
   1491                 # is not fixed.
   1492                 try:
   1493                     meas_array = meas[numpy.bitwise_and(tstart < t, t < tend)]
   1494                 except ValueError, e:
   1495                     logging.debug('Error logging measurements: %s', str(e))
   1496                     logging.debug('timestamps %d %s' % (t.len, t))
   1497                     logging.debug('timestamp start, end %f %f' % (tstart, tend))
   1498                     logging.debug('measurements %d %s' % (meas.len, meas))
   1499 
   1500                 # If sub-test terminated early, avoid calculating avg, std and
   1501                 # min
   1502                 if not meas_array.size:
   1503                     continue
   1504                 meas_mean = meas_array.mean()
   1505                 meas_std = meas_array.std()
   1506 
   1507                 # Results list can be used for pretty printing and saving as csv
   1508                 results.append((prefix, meas_mean, meas_std,
   1509                                 tend - tstart, tstart, tend))
   1510                 keyvals[prefix + '_' + mtype] = list(meas_array)
   1511                 keyvals[prefix + '_' + mtype + '_avg'] = meas_mean
   1512                 keyvals[prefix + '_' + mtype + '_cnt'] = meas_array.size
   1513                 keyvals[prefix + '_' + mtype + '_max'] = meas_array.max()
   1514                 keyvals[prefix + '_' + mtype + '_min'] = meas_array.min()
   1515                 keyvals[prefix + '_' + mtype + '_std'] = meas_std
   1516         self._results = results
   1517         return keyvals
   1518 
   1519 
   1520     def save_results(self, resultsdir, fname=None):
   1521         """Save computed results in a nice tab-separated format.
   1522         This is useful for long manual runs.
   1523 
   1524         Args:
   1525             resultsdir: String, directory to write results to
   1526             fname: String name of file to write results to
   1527         """
   1528         if not fname:
   1529             fname = 'meas_results_%.0f.txt' % time.time()
   1530         fname = os.path.join(resultsdir, fname)
   1531         with file(fname, 'wt') as f:
   1532             for row in self._results:
   1533                 # First column is name, the rest are numbers. See _calc_power()
   1534                 fmt_row = [row[0]] + ['%.2f' % x for x in row[1:]]
   1535                 line = '\t'.join(fmt_row)
   1536                 f.write(line + '\n')
   1537 
   1538 
   1539 class PowerLogger(MeasurementLogger):
   1540     def save_results(self, resultsdir, fname=None):
   1541         if not fname:
   1542             fname = 'power_results_%.0f.txt' % time.time()
   1543         super(PowerLogger, self).save_results(resultsdir, fname)
   1544 
   1545 
   1546     def calc(self, mtype='pwr'):
   1547         return super(PowerLogger, self).calc(mtype)
   1548 
   1549 
   1550 class TempMeasurement(object):
   1551     """Class to measure temperature.
   1552 
   1553     Public attributes:
   1554         domain: String name of the temperature domain being measured.  Example is
   1555           'cpu' for cpu temperature
   1556 
   1557     Private attributes:
   1558         _path: Path to temperature file to read ( in millidegrees Celsius )
   1559 
   1560     Public methods:
   1561         refresh: Performs any temperature sampling and calculation and returns
   1562             temperature as float in degrees Celsius.
   1563     """
   1564     def __init__(self, domain, path):
   1565         """Constructor."""
   1566         self.domain = domain
   1567         self._path = path
   1568 
   1569 
   1570     def refresh(self):
   1571         """Performs temperature
   1572 
   1573         Returns:
   1574             float, temperature in degrees Celsius
   1575         """
   1576         return int(utils.read_one_line(self._path)) / 1000.
   1577 
   1578 
   1579 class TempLogger(MeasurementLogger):
   1580     """A thread that logs temperature readings in millidegrees Celsius."""
   1581     def __init__(self, measurements, seconds_period=30.0):
   1582         if not measurements:
   1583             measurements = []
   1584             tstats = ThermalStatHwmon()
   1585             for kname in tstats.fields:
   1586                 match = re.match(r'(\S+)_temp(\d+)_input', kname)
   1587                 if not match:
   1588                     continue
   1589                 domain = match.group(1) + '-t' + match.group(2)
   1590                 fpath = tstats.fields[kname][0]
   1591                 new_meas = TempMeasurement(domain, fpath)
   1592                 measurements.append(new_meas)
   1593         super(TempLogger, self).__init__(measurements, seconds_period)
   1594 
   1595 
   1596     def save_results(self, resultsdir, fname=None):
   1597         if not fname:
   1598             fname = 'temp_results_%.0f.txt' % time.time()
   1599         super(TempLogger, self).save_results(resultsdir, fname)
   1600 
   1601 
   1602     def calc(self, mtype='temp'):
   1603         return super(TempLogger, self).calc(mtype)
   1604 
   1605 
   1606 class DiskStateLogger(threading.Thread):
   1607     """Records the time percentages the disk stays in its different power modes.
   1608 
   1609     Example code snippet:
   1610         mylogger = power_status.DiskStateLogger()
   1611         mylogger.start()
   1612         result = mylogger.result()
   1613 
   1614     Public methods:
   1615         start: Launches the thread and starts measurements.
   1616         result: Stops the thread if it's still running and returns measurements.
   1617         get_error: Returns the exception in _error if it exists.
   1618 
   1619     Private functions:
   1620         _get_disk_state: Returns the disk's current ATA power mode as a string.
   1621 
   1622     Private attributes:
   1623         _seconds_period: Disk polling interval in seconds.
   1624         _stats: Dict that maps disk states to seconds spent in them.
   1625         _running: Flag that is True as long as the logger should keep running.
   1626         _time: Timestamp of last disk state reading.
   1627         _device_path: The file system path of the disk's device node.
   1628         _error: Contains a TestError exception if an unexpected error occured
   1629     """
   1630     def __init__(self, seconds_period = 5.0, device_path = None):
   1631         """Initializes a logger.
   1632 
   1633         Args:
   1634             seconds_period: Disk polling interval in seconds. Default 5.0
   1635             device_path: The path of the disk's device node. Default '/dev/sda'
   1636         """
   1637         threading.Thread.__init__(self)
   1638         self._seconds_period = seconds_period
   1639         self._device_path = device_path
   1640         self._stats = {}
   1641         self._running = False
   1642         self._error = None
   1643 
   1644         result = utils.system_output('rootdev -s')
   1645         # TODO(tbroch) Won't work for emmc storage and will throw this error in
   1646         # keyvals : 'ioctl(SG_IO) error: [Errno 22] Invalid argument'
   1647         # Lets implement something complimentary for emmc
   1648         if not device_path:
   1649             self._device_path = \
   1650                 re.sub('(sd[a-z]|mmcblk[0-9]+)p?[0-9]+', '\\1', result)
   1651         logging.debug("device_path = %s", self._device_path)
   1652 
   1653 
   1654     def start(self):
   1655         logging.debug("inside DiskStateLogger.start")
   1656         if os.path.exists(self._device_path):
   1657             logging.debug("DiskStateLogger started")
   1658             super(DiskStateLogger, self).start()
   1659 
   1660 
   1661     def _get_disk_state(self):
   1662         """Checks the disk's power mode and returns it as a string.
   1663 
   1664         This uses the SG_IO ioctl to issue a raw SCSI command data block with
   1665         the ATA-PASS-THROUGH command that allows SCSI-to-ATA translation (see
   1666         T10 document 04-262r8). The ATA command issued is CHECKPOWERMODE1,
   1667         which returns the device's current power mode.
   1668         """
   1669 
   1670         def _addressof(obj):
   1671             """Shortcut to return the memory address of an object as integer."""
   1672             return ctypes.cast(obj, ctypes.c_void_p).value
   1673 
   1674         scsi_cdb = struct.pack("12B", # SCSI command data block (uint8[12])
   1675                                0xa1, # SCSI opcode: ATA-PASS-THROUGH
   1676                                3 << 1, # protocol: Non-data
   1677                                1 << 5, # flags: CK_COND
   1678                                0, # features
   1679                                0, # sector count
   1680                                0, 0, 0, # LBA
   1681                                1 << 6, # flags: ATA-USING-LBA
   1682                                0xe5, # ATA opcode: CHECKPOWERMODE1
   1683                                0, # reserved
   1684                                0, # control (no idea what this is...)
   1685                               )
   1686         scsi_sense = (ctypes.c_ubyte * 32)() # SCSI sense buffer (uint8[32])
   1687         sgio_header = struct.pack("iiBBHIPPPIIiPBBBBHHiII", # see <scsi/sg.h>
   1688                                   83, # Interface ID magic number (int32)
   1689                                   -1, # data transfer direction: none (int32)
   1690                                   12, # SCSI command data block length (uint8)
   1691                                   32, # SCSI sense data block length (uint8)
   1692                                   0, # iovec_count (not applicable?) (uint16)
   1693                                   0, # data transfer length (uint32)
   1694                                   0, # data block pointer
   1695                                   _addressof(scsi_cdb), # SCSI CDB pointer
   1696                                   _addressof(scsi_sense), # sense buffer pointer
   1697                                   500, # timeout in milliseconds (uint32)
   1698                                   0, # flags (uint32)
   1699                                   0, # pack ID (unused) (int32)
   1700                                   0, # user data pointer (unused)
   1701                                   0, 0, 0, 0, 0, 0, 0, 0, 0, # output params
   1702                                  )
   1703         try:
   1704             with open(self._device_path, 'r') as dev:
   1705                 result = fcntl.ioctl(dev, 0x2285, sgio_header)
   1706         except IOError, e:
   1707             raise error.TestError('ioctl(SG_IO) error: %s' % str(e))
   1708         _, _, _, _, status, host_status, driver_status = \
   1709             struct.unpack("4x4xxx2x4xPPP4x4x4xPBxxxHH4x4x4x", result)
   1710         if status != 0x2: # status: CHECK_CONDITION
   1711             raise error.TestError('SG_IO status: %d' % status)
   1712         if host_status != 0:
   1713             raise error.TestError('SG_IO host status: %d' % host_status)
   1714         if driver_status != 0x8: # driver status: SENSE
   1715             raise error.TestError('SG_IO driver status: %d' % driver_status)
   1716 
   1717         if scsi_sense[0] != 0x72: # resp. code: current error, descriptor format
   1718             raise error.TestError('SENSE response code: %d' % scsi_sense[0])
   1719         if scsi_sense[1] != 0: # sense key: No Sense
   1720             raise error.TestError('SENSE key: %d' % scsi_sense[1])
   1721         if scsi_sense[7] < 14: # additional length (ATA status is 14 - 1 bytes)
   1722             raise error.TestError('ADD. SENSE too short: %d' % scsi_sense[7])
   1723         if scsi_sense[8] != 0x9: # additional descriptor type: ATA Return Status
   1724             raise error.TestError('SENSE descriptor type: %d' % scsi_sense[8])
   1725         if scsi_sense[11] != 0: # errors: none
   1726             raise error.TestError('ATA error code: %d' % scsi_sense[11])
   1727 
   1728         if scsi_sense[13] == 0x00:
   1729             return 'standby'
   1730         if scsi_sense[13] == 0x80:
   1731             return 'idle'
   1732         if scsi_sense[13] == 0xff:
   1733             return 'active'
   1734         return 'unknown(%d)' % scsi_sense[13]
   1735 
   1736 
   1737     def run(self):
   1738         """The Thread's run method."""
   1739         try:
   1740             self._time = time.time()
   1741             self._running = True
   1742             while(self._running):
   1743                 time.sleep(self._seconds_period)
   1744                 state = self._get_disk_state()
   1745                 new_time = time.time()
   1746                 if state in self._stats:
   1747                     self._stats[state] += new_time - self._time
   1748                 else:
   1749                     self._stats[state] = new_time - self._time
   1750                 self._time = new_time
   1751         except error.TestError, e:
   1752             self._error = e
   1753             self._running = False
   1754 
   1755 
   1756     def result(self):
   1757         """Stop the logger and return dict with result percentages."""
   1758         if (self._running):
   1759             self._running = False
   1760             self.join(self._seconds_period * 2)
   1761         return AbstractStats.to_percent(self._stats)
   1762 
   1763 
   1764     def get_error(self):
   1765         """Returns the _error exception... please only call after result()."""
   1766         return self._error
   1767 
   1768 def parse_pmc_s0ix_residency_info():
   1769     """
   1770     Parses S0ix residency for PMC based Intel systems
   1771     (skylake/kabylake/apollolake), the debugfs paths might be
   1772     different from platform to platform, yet the format is
   1773     unified in microseconds.
   1774 
   1775     @returns residency in seconds.
   1776     @raises error.TestNAError if the debugfs file not found.
   1777     """
   1778     info_path = None
   1779     for node in ['/sys/kernel/debug/pmc_core/slp_s0_residency_usec',
   1780                  '/sys/kernel/debug/telemetry/s0ix_residency_usec']:
   1781         if os.path.exists(node):
   1782             info_path = node
   1783             break
   1784     if not info_path:
   1785         raise error.TestNAError('S0ix residency file not found')
   1786     return float(utils.read_one_line(info_path)) * 1e-6
   1787 
   1788 
   1789 class S0ixResidencyStats(object):
   1790     """
   1791     Measures the S0ix residency of a given board over time.
   1792     """
   1793     def __init__(self):
   1794         self._initial_residency = parse_pmc_s0ix_residency_info()
   1795 
   1796     def get_accumulated_residency_secs(self):
   1797         """
   1798         @returns S0ix Residency since the class has been initialized.
   1799         """
   1800         return parse_pmc_s0ix_residency_info() - self._initial_residency
   1801