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