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 5import collections, ctypes, fcntl, glob, logging, math, numpy, os, re, struct 6import threading, time 7 8from autotest_lib.client.bin import utils 9from autotest_lib.client.common_lib import error, enum 10from autotest_lib.client.cros import kernel_trace 11 12BatteryDataReportType = enum.Enum('CHARGE', 'ENERGY') 13 14# battery data reported at 1e6 scale 15BATTERY_DATA_SCALE = 1e6 16# number of times to retry reading the battery in the case of bad data 17BATTERY_RETRY_COUNT = 3 18 19class 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 59class 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 124class 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 173class 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 214class 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 344class 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 356class 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 381class 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 raise error.TestError( 477 'Running on AC power. Please remove AC power cable.') 478 479 percent_initial_charge = self.percent_current_charge() 480 481 if percent_initial_charge_min and percent_initial_charge < \ 482 percent_initial_charge_min: 483 raise error.TestError('Initial charge (%f) less than min (%f)' 484 % (percent_initial_charge, percent_initial_charge_min)) 485 486 487def get_status(): 488 """ 489 Return a new power status object (SysStat). A new power status snapshot 490 for a given host can be obtained by either calling this routine again and 491 constructing a new SysStat object, or by using the refresh method of the 492 SysStat object. 493 """ 494 status = SysStat() 495 status.refresh() 496 return status 497 498 499class AbstractStats(object): 500 """ 501 Common superclass for measurements of percentages per state over time. 502 503 Public Attributes: 504 incremental: If False, stats returned are from a single 505 _read_stats. Otherwise, stats are from the difference between 506 the current and last refresh. 507 """ 508 509 @staticmethod 510 def to_percent(stats): 511 """ 512 Turns a dict with absolute time values into a dict with percentages. 513 """ 514 total = sum(stats.itervalues()) 515 if total == 0: 516 return {} 517 return dict((k, v * 100.0 / total) for (k, v) in stats.iteritems()) 518 519 520 @staticmethod 521 def do_diff(new, old): 522 """ 523 Returns a dict with value deltas from two dicts with matching keys. 524 """ 525 return dict((k, new[k] - old.get(k, 0)) for k in new.iterkeys()) 526 527 528 @staticmethod 529 def format_results_percent(results, name, percent_stats): 530 """ 531 Formats autotest result keys to format: 532 percent_<name>_<key>_time 533 """ 534 for key in percent_stats: 535 results['percent_%s_%s_time' % (name, key)] = percent_stats[key] 536 537 538 @staticmethod 539 def format_results_wavg(results, name, wavg): 540 """ 541 Add an autotest result keys to format: wavg_<name> 542 """ 543 if wavg is not None: 544 results['wavg_%s' % (name)] = wavg 545 546 547 def __init__(self, name=None, incremental=True): 548 if not name: 549 error.TestFail("Need to name AbstractStats instance please.") 550 self.name = name 551 self.incremental = incremental 552 self._stats = self._read_stats() 553 554 555 def refresh(self): 556 """ 557 Returns dict mapping state names to percentage of time spent in them. 558 """ 559 raw_stats = result = self._read_stats() 560 if self.incremental: 561 result = self.do_diff(result, self._stats) 562 self._stats = raw_stats 563 return self.to_percent(result) 564 565 566 def _automatic_weighted_average(self): 567 """ 568 Turns a dict with absolute times (or percentages) into a weighted 569 average value. 570 """ 571 total = sum(self._stats.itervalues()) 572 if total == 0: 573 return None 574 575 return sum((float(k)*v) / total for (k, v) in self._stats.iteritems()) 576 577 578 def _supports_automatic_weighted_average(self): 579 """ 580 Override! 581 582 Returns True if stats collected can be automatically converted from 583 percent distribution to weighted average. False otherwise. 584 """ 585 return False 586 587 588 def weighted_average(self): 589 """ 590 Return weighted average calculated using the automated average method 591 (if supported) or using a custom method defined by the stat. 592 """ 593 if self._supports_automatic_weighted_average(): 594 return self._automatic_weighted_average() 595 596 return self._weighted_avg_fn() 597 598 599 def _weighted_avg_fn(self): 600 """ 601 Override! Custom weighted average function. 602 603 Returns weighted average as a single floating point value. 604 """ 605 return None 606 607 608 def _read_stats(self): 609 """ 610 Override! Reads the raw data values that shall be measured into a dict. 611 """ 612 raise NotImplementedError('Override _read_stats in the subclass!') 613 614 615class CPUFreqStats(AbstractStats): 616 """ 617 CPU Frequency statistics 618 """ 619 620 def __init__(self, start_cpu=-1, end_cpu=-1): 621 cpufreq_stats_path = '/sys/devices/system/cpu/cpu*/cpufreq/stats/' + \ 622 'time_in_state' 623 intel_pstate_stats_path = '/sys/devices/system/cpu/intel_pstate/' + \ 624 'aperf_mperf' 625 self._file_paths = glob.glob(cpufreq_stats_path) 626 num_cpus = len(self._file_paths) 627 self._intel_pstate_file_paths = glob.glob(intel_pstate_stats_path) 628 self._running_intel_pstate = False 629 self._initial_perf = None 630 self._current_perf = None 631 self._max_freq = 0 632 name = 'cpufreq' 633 if not self._file_paths: 634 logging.debug('time_in_state file not found') 635 if self._intel_pstate_file_paths: 636 logging.debug('intel_pstate frequency stats file found') 637 self._running_intel_pstate = True 638 else: 639 if (start_cpu >= 0 and end_cpu >= 0 640 and not (start_cpu == 0 and end_cpu == num_cpus - 1)): 641 self._file_paths = self._file_paths[start_cpu : end_cpu] 642 name += '_' + str(start_cpu) + '_' + str(end_cpu) 643 644 super(CPUFreqStats, self).__init__(name=name) 645 646 647 def _read_stats(self): 648 if self._running_intel_pstate: 649 aperf = 0 650 mperf = 0 651 652 for path in self._intel_pstate_file_paths: 653 if not os.path.exists(path): 654 logging.debug('%s is not found', path) 655 continue 656 data = utils.read_file(path) 657 for line in data.splitlines(): 658 pair = line.split() 659 # max_freq is supposed to be the same for all CPUs 660 # and remain constant throughout. 661 # So, we set the entry only once 662 if not self._max_freq: 663 self._max_freq = int(pair[0]) 664 aperf += int(pair[1]) 665 mperf += int(pair[2]) 666 667 if not self._initial_perf: 668 self._initial_perf = (aperf, mperf) 669 670 self._current_perf = (aperf, mperf) 671 672 stats = {} 673 for path in self._file_paths: 674 if not os.path.exists(path): 675 logging.debug('%s is not found', path) 676 continue 677 678 data = utils.read_file(path) 679 for line in data.splitlines(): 680 pair = line.split() 681 freq = int(pair[0]) 682 timeunits = int(pair[1]) 683 if freq in stats: 684 stats[freq] += timeunits 685 else: 686 stats[freq] = timeunits 687 return stats 688 689 690 def _supports_automatic_weighted_average(self): 691 return not self._running_intel_pstate 692 693 694 def _weighted_avg_fn(self): 695 if not self._running_intel_pstate: 696 return None 697 698 if self._current_perf[1] != self._initial_perf[1]: 699 # Avg freq = max_freq * aperf_delta / mperf_delta 700 return self._max_freq * \ 701 float(self._current_perf[0] - self._initial_perf[0]) / \ 702 (self._current_perf[1] - self._initial_perf[1]) 703 return 1.0 704 705 706class CPUIdleStats(AbstractStats): 707 """ 708 CPU Idle statistics (refresh() will not work with incremental=False!) 709 """ 710 # TODO (snanda): Handle changes in number of c-states due to events such 711 # as ac <-> battery transitions. 712 # TODO (snanda): Handle non-S0 states. Time spent in suspend states is 713 # currently not factored out. 714 def __init__(self, start_cpu=-1, end_cpu=-1): 715 cpuidle_path = '/sys/devices/system/cpu/cpu*/cpuidle' 716 self._cpus = glob.glob(cpuidle_path) 717 num_cpus = len(self._cpus) 718 name = 'cpuidle' 719 if (start_cpu >= 0 and end_cpu >= 0 720 and not (start_cpu == 0 and end_cpu == num_cpus - 1)): 721 self._cpus = self._cpus[start_cpu : end_cpu] 722 name = name + '_' + str(start_cpu) + '_' + str(end_cpu) 723 super(CPUIdleStats, self).__init__(name=name) 724 725 726 def _read_stats(self): 727 cpuidle_stats = collections.defaultdict(int) 728 epoch_usecs = int(time.time() * 1000 * 1000) 729 for cpu in self._cpus: 730 state_path = os.path.join(cpu, 'state*') 731 states = glob.glob(state_path) 732 cpuidle_stats['C0'] += epoch_usecs 733 734 for state in states: 735 name = utils.read_one_line(os.path.join(state, 'name')) 736 latency = utils.read_one_line(os.path.join(state, 'latency')) 737 738 if not int(latency) and name == 'POLL': 739 # C0 state. Kernel stats aren't right, so calculate by 740 # subtracting all other states from total time (using epoch 741 # timer since we calculate differences in the end anyway). 742 # NOTE: Only x86 lists C0 under cpuidle, ARM does not. 743 continue 744 745 usecs = int(utils.read_one_line(os.path.join(state, 'time'))) 746 cpuidle_stats['C0'] -= usecs 747 748 if name == '<null>': 749 # Kernel race condition that can happen while a new C-state 750 # gets added (e.g. AC->battery). Don't know the 'name' of 751 # the state yet, but its 'time' would be 0 anyway. 752 logging.warning('Read name: <null>, time: %d from %s' 753 % (usecs, state) + '... skipping.') 754 continue 755 756 cpuidle_stats[name] += usecs 757 758 return cpuidle_stats 759 760 761class CPUPackageStats(AbstractStats): 762 """ 763 Package C-state residency statistics for modern Intel CPUs. 764 """ 765 766 ATOM = {'C2': 0x3F8, 'C4': 0x3F9, 'C6': 0x3FA} 767 NEHALEM = {'C3': 0x3F8, 'C6': 0x3F9, 'C7': 0x3FA} 768 SANDY_BRIDGE = {'C2': 0x60D, 'C3': 0x3F8, 'C6': 0x3F9, 'C7': 0x3FA} 769 HASWELL = {'C2': 0x60D, 'C3': 0x3F8, 'C6': 0x3F9, 'C7': 0x3FA, 770 'C8': 0x630, 'C9': 0x631,'C10': 0x632} 771 772 def __init__(self): 773 def _get_platform_states(): 774 """ 775 Helper to decide what set of microarchitecture-specific MSRs to use. 776 777 Returns: dict that maps C-state name to MSR address, or None. 778 """ 779 modalias = '/sys/devices/system/cpu/modalias' 780 if not os.path.exists(modalias): 781 return None 782 783 values = utils.read_one_line(modalias).split(':') 784 # values[2]: vendor, values[4]: family, values[6]: model (CPUID) 785 if values[2] != '0000' or values[4] != '0006': 786 return None 787 788 return { 789 # model groups pulled from Intel manual, volume 3 chapter 35 790 '0027': self.ATOM, # unreleased? (Next Generation Atom) 791 '001A': self.NEHALEM, # Bloomfield, Nehalem-EP (i7/Xeon) 792 '001E': self.NEHALEM, # Clarks-/Lynnfield, Jasper (i5/i7/X) 793 '001F': self.NEHALEM, # unreleased? (abandoned?) 794 '0025': self.NEHALEM, # Arran-/Clarksdale (i3/i5/i7/C/X) 795 '002C': self.NEHALEM, # Gulftown, Westmere-EP (i7/Xeon) 796 '002E': self.NEHALEM, # Nehalem-EX (Xeon) 797 '002F': self.NEHALEM, # Westmere-EX (Xeon) 798 '002A': self.SANDY_BRIDGE, # SandyBridge (i3/i5/i7/C/X) 799 '002D': self.SANDY_BRIDGE, # SandyBridge-E (i7) 800 '003A': self.SANDY_BRIDGE, # IvyBridge (i3/i5/i7/X) 801 '003C': self.HASWELL, # Haswell (Core/Xeon) 802 '003D': self.HASWELL, # Broadwell (Core) 803 '003E': self.SANDY_BRIDGE, # IvyBridge (Xeon) 804 '003F': self.HASWELL, # Haswell-E (Core/Xeon) 805 '004F': self.HASWELL, # Broadwell (Xeon) 806 '0056': self.HASWELL, # Broadwell (Xeon D) 807 }.get(values[6], None) 808 809 self._platform_states = _get_platform_states() 810 super(CPUPackageStats, self).__init__(name='cpupkg') 811 812 813 def _read_stats(self): 814 packages = set() 815 template = '/sys/devices/system/cpu/cpu%s/topology/physical_package_id' 816 if not self._platform_states: 817 return {} 818 stats = dict((state, 0) for state in self._platform_states) 819 stats['C0_C1'] = 0 820 821 for cpu in os.listdir('/dev/cpu'): 822 if not os.path.exists(template % cpu): 823 continue 824 package = utils.read_one_line(template % cpu) 825 if package in packages: 826 continue 827 packages.add(package) 828 829 stats['C0_C1'] += utils.rdmsr(0x10, cpu) # TSC 830 for (state, msr) in self._platform_states.iteritems(): 831 ticks = utils.rdmsr(msr, cpu) 832 stats[state] += ticks 833 stats['C0_C1'] -= ticks 834 835 return stats 836 837 838class DevFreqStats(AbstractStats): 839 """ 840 Devfreq device frequency stats. 841 """ 842 843 _DIR = '/sys/class/devfreq' 844 845 846 def __init__(self, f): 847 """Constructs DevFreqStats Object that track frequency stats 848 for the path of the given Devfreq device. 849 850 The frequencies for devfreq devices are listed in Hz. 851 852 Args: 853 path: the path to the devfreq device 854 855 Example: 856 /sys/class/devfreq/dmc 857 """ 858 self._path = os.path.join(self._DIR, f) 859 if not os.path.exists(self._path): 860 raise error.TestError('DevFreqStats: devfreq device does not exist') 861 862 fname = os.path.join(self._path, 'available_frequencies') 863 af = utils.read_one_line(fname).strip() 864 self._available_freqs = sorted(af.split(), key=int) 865 866 super(DevFreqStats, self).__init__(name=f) 867 868 def _read_stats(self): 869 stats = dict((freq, 0) for freq in self._available_freqs) 870 fname = os.path.join(self._path, 'trans_stat') 871 872 with open(fname) as fd: 873 # The lines that contain the time in each frequency start on the 3rd 874 # line, so skip the first 2 lines. The last line contains the number 875 # of transitions, so skip that line too. 876 # The time in each frequency is at the end of the line. 877 freq_pattern = re.compile(r'\d+(?=:)') 878 for line in fd.readlines()[2:-1]: 879 freq = freq_pattern.search(line) 880 if freq and freq.group() in self._available_freqs: 881 stats[freq.group()] = int(line.strip().split()[-1]) 882 883 return stats 884 885 886class GPUFreqStats(AbstractStats): 887 """GPU Frequency statistics class. 888 889 TODO(tbroch): add stats for other GPUs 890 """ 891 892 _MALI_DEV = '/sys/class/misc/mali0/device' 893 _MALI_EVENTS = ['mali_dvfs:mali_dvfs_set_clock'] 894 _MALI_TRACE_CLK_RE = r'(\d+.\d+): mali_dvfs_set_clock: frequency=(\d+)\d{6}' 895 896 _I915_ROOT = '/sys/kernel/debug/dri/0' 897 _I915_EVENTS = ['i915:intel_gpu_freq_change'] 898 _I915_CLK = os.path.join(_I915_ROOT, 'i915_cur_delayinfo') 899 _I915_TRACE_CLK_RE = r'(\d+.\d+): intel_gpu_freq_change: new_freq=(\d+)' 900 _I915_CUR_FREQ_RE = r'CAGF:\s+(\d+)MHz' 901 _I915_MIN_FREQ_RE = r'Lowest \(RPN\) frequency:\s+(\d+)MHz' 902 _I915_MAX_FREQ_RE = r'Max non-overclocked \(RP0\) frequency:\s+(\d+)MHz' 903 # TODO(dbasehore) parse this from debugfs if/when this value is added 904 _I915_FREQ_STEP = 50 905 906 _gpu_type = None 907 908 909 def _get_mali_freqs(self): 910 """Get mali clocks based on kernel version. 911 912 For 3.8-3.18: 913 # cat /sys/class/misc/mali0/device/clock 914 100000000 915 # cat /sys/class/misc/mali0/device/available_frequencies 916 100000000 917 160000000 918 266000000 919 350000000 920 400000000 921 450000000 922 533000000 923 533000000 924 925 For 4.4+: 926 Tracked in DevFreqStats 927 928 Returns: 929 cur_mhz: string of current GPU clock in mhz 930 """ 931 cur_mhz = None 932 fqs = [] 933 934 fname = os.path.join(self._MALI_DEV, 'clock') 935 if os.path.exists(fname): 936 cur_mhz = str(int(int(utils.read_one_line(fname).strip()) / 1e6)) 937 fname = os.path.join(self._MALI_DEV, 'available_frequencies') 938 with open(fname) as fd: 939 for ln in fd.readlines(): 940 freq = int(int(ln.strip()) / 1e6) 941 fqs.append(str(freq)) 942 fqs.sort() 943 944 self._freqs = fqs 945 return cur_mhz 946 947 948 def __init__(self, incremental=False): 949 950 951 min_mhz = None 952 max_mhz = None 953 cur_mhz = None 954 events = None 955 self._freqs = [] 956 self._prev_sample = None 957 self._trace = None 958 959 if os.path.exists(self._MALI_DEV) and \ 960 not os.path.exists(os.path.join(self._MALI_DEV, "devfreq")): 961 self._set_gpu_type('mali') 962 elif os.path.exists(self._I915_CLK): 963 self._set_gpu_type('i915') 964 else: 965 # We either don't know how to track GPU stats (yet) or the stats are 966 # tracked in DevFreqStats. 967 self._set_gpu_type(None) 968 969 logging.debug("gpu_type is %s", self._gpu_type) 970 971 if self._gpu_type is 'mali': 972 events = self._MALI_EVENTS 973 cur_mhz = self._get_mali_freqs() 974 if self._freqs: 975 min_mhz = self._freqs[0] 976 max_mhz = self._freqs[-1] 977 978 elif self._gpu_type is 'i915': 979 events = self._I915_EVENTS 980 with open(self._I915_CLK) as fd: 981 for ln in fd.readlines(): 982 logging.debug("ln = %s", ln) 983 result = re.findall(self._I915_CUR_FREQ_RE, ln) 984 if result: 985 cur_mhz = result[0] 986 continue 987 result = re.findall(self._I915_MIN_FREQ_RE, ln) 988 if result: 989 min_mhz = result[0] 990 continue 991 result = re.findall(self._I915_MAX_FREQ_RE, ln) 992 if result: 993 max_mhz = result[0] 994 continue 995 if min_mhz and max_mhz: 996 for i in xrange(int(min_mhz), int(max_mhz) + 997 self._I915_FREQ_STEP, self._I915_FREQ_STEP): 998 self._freqs.append(str(i)) 999 1000 logging.debug("cur_mhz = %s, min_mhz = %s, max_mhz = %s", cur_mhz, 1001 min_mhz, max_mhz) 1002 1003 if cur_mhz and min_mhz and max_mhz: 1004 self._trace = kernel_trace.KernelTrace(events=events) 1005 1006 # Not all platforms or kernel versions support tracing. 1007 if not self._trace or not self._trace.is_tracing(): 1008 logging.warning("GPU frequency tracing not enabled.") 1009 else: 1010 self._prev_sample = (cur_mhz, self._trace.uptime_secs()) 1011 logging.debug("Current GPU freq: %s", cur_mhz) 1012 logging.debug("All GPU freqs: %s", self._freqs) 1013 1014 super(GPUFreqStats, self).__init__(name='gpu', incremental=incremental) 1015 1016 1017 @classmethod 1018 def _set_gpu_type(cls, gpu_type): 1019 cls._gpu_type = gpu_type 1020 1021 1022 def _read_stats(self): 1023 if self._gpu_type: 1024 return getattr(self, "_%s_read_stats" % self._gpu_type)() 1025 return {} 1026 1027 1028 def _trace_read_stats(self, regexp): 1029 """Read GPU stats from kernel trace outputs. 1030 1031 Args: 1032 regexp: regular expression to match trace output for frequency 1033 1034 Returns: 1035 Dict with key string in mhz and val float in seconds. 1036 """ 1037 if not self._prev_sample: 1038 return {} 1039 1040 stats = dict((k, 0.0) for k in self._freqs) 1041 results = self._trace.read(regexp=regexp) 1042 for (tstamp_str, freq) in results: 1043 tstamp = float(tstamp_str) 1044 1045 # do not reparse lines in trace buffer 1046 if tstamp <= self._prev_sample[1]: 1047 continue 1048 delta = tstamp - self._prev_sample[1] 1049 logging.debug("freq:%s tstamp:%f - %f delta:%f", 1050 self._prev_sample[0], 1051 tstamp, self._prev_sample[1], 1052 delta) 1053 stats[self._prev_sample[0]] += delta 1054 self._prev_sample = (freq, tstamp) 1055 1056 # Do last record 1057 delta = self._trace.uptime_secs() - self._prev_sample[1] 1058 logging.debug("freq:%s tstamp:uptime - %f delta:%f", 1059 self._prev_sample[0], 1060 self._prev_sample[1], delta) 1061 stats[self._prev_sample[0]] += delta 1062 1063 logging.debug("GPU freq percents:%s", stats) 1064 return stats 1065 1066 1067 def _mali_read_stats(self): 1068 """Read Mali GPU stats 1069 1070 Frequencies are reported in Hz, so use a regex that drops the last 6 1071 digits. 1072 1073 Output in trace looks like this: 1074 1075 kworker/u:24-5220 [000] .... 81060.329232: mali_dvfs_set_clock: frequency=400 1076 kworker/u:24-5220 [000] .... 81061.830128: mali_dvfs_set_clock: frequency=350 1077 1078 Returns: 1079 Dict with frequency in mhz as key and float in seconds for time 1080 spent at that frequency. 1081 """ 1082 return self._trace_read_stats(self._MALI_TRACE_CLK_RE) 1083 1084 1085 def _i915_read_stats(self): 1086 """Read i915 GPU stats. 1087 1088 Output looks like this (kernel >= 3.8): 1089 1090 kworker/u:0-28247 [000] .... 259391.579610: intel_gpu_freq_change: new_freq=400 1091 kworker/u:0-28247 [000] .... 259391.581797: intel_gpu_freq_change: new_freq=350 1092 1093 Returns: 1094 Dict with frequency in mhz as key and float in seconds for time 1095 spent at that frequency. 1096 """ 1097 return self._trace_read_stats(self._I915_TRACE_CLK_RE) 1098 1099 1100class USBSuspendStats(AbstractStats): 1101 """ 1102 USB active/suspend statistics (over all devices) 1103 """ 1104 # TODO (snanda): handle hot (un)plugging of USB devices 1105 # TODO (snanda): handle duration counters wraparound 1106 1107 def __init__(self): 1108 usb_stats_path = '/sys/bus/usb/devices/*/power' 1109 self._file_paths = glob.glob(usb_stats_path) 1110 if not self._file_paths: 1111 logging.debug('USB stats path not found') 1112 super(USBSuspendStats, self).__init__(name='usb') 1113 1114 1115 def _read_stats(self): 1116 usb_stats = {'active': 0, 'suspended': 0} 1117 1118 for path in self._file_paths: 1119 active_duration_path = os.path.join(path, 'active_duration') 1120 total_duration_path = os.path.join(path, 'connected_duration') 1121 1122 if not os.path.exists(active_duration_path) or \ 1123 not os.path.exists(total_duration_path): 1124 logging.debug('duration paths do not exist for: %s', path) 1125 continue 1126 1127 active = int(utils.read_file(active_duration_path)) 1128 total = int(utils.read_file(total_duration_path)) 1129 logging.debug('device %s active for %.2f%%', 1130 path, active * 100.0 / total) 1131 1132 usb_stats['active'] += active 1133 usb_stats['suspended'] += total - active 1134 1135 return usb_stats 1136 1137 1138def get_cpu_sibling_groups(): 1139 """ 1140 Get CPU core groups in HMP systems. 1141 1142 In systems with both small core and big core, 1143 returns groups of small and big sibling groups. 1144 """ 1145 siblings_paths = '/sys/devices/system/cpu/cpu*/topology/' + \ 1146 'core_siblings_list' 1147 sibling_groups = [] 1148 sibling_file_paths = glob.glob(siblings_paths) 1149 if not len(sibling_file_paths) > 0: 1150 return sibling_groups; 1151 total_cpus = len(sibling_file_paths) 1152 i = 0 1153 sibling_list_pattern = re.compile('(\d+)-(\d+)') 1154 while (i < total_cpus): 1155 siblings_data = utils.read_file(sibling_file_paths[i]) 1156 sibling_match = sibling_list_pattern.match(siblings_data) 1157 sibling_start, sibling_end = (int(x) for x in sibling_match.groups()) 1158 sibling_groups.append((sibling_start, sibling_end)) 1159 i = sibling_end + 1 1160 return sibling_groups 1161 1162 1163 1164class StatoMatic(object): 1165 """Class to aggregate and monitor a bunch of power related statistics.""" 1166 def __init__(self): 1167 self._start_uptime_secs = kernel_trace.KernelTrace.uptime_secs() 1168 self._astats = [USBSuspendStats(), 1169 GPUFreqStats(incremental=False), 1170 CPUPackageStats()] 1171 cpu_sibling_groups = get_cpu_sibling_groups() 1172 if not len(cpu_sibling_groups): 1173 self._astats.append(CPUFreqStats()) 1174 self._astats.append(CPUIdleStats()) 1175 for cpu_start, cpu_end in cpu_sibling_groups: 1176 self._astats.append(CPUFreqStats(cpu_start, cpu_end)) 1177 self._astats.append(CPUIdleStats(cpu_start, cpu_end)) 1178 if os.path.isdir(DevFreqStats._DIR): 1179 self._astats.extend([DevFreqStats(f) for f in \ 1180 os.listdir(DevFreqStats._DIR)]) 1181 1182 self._disk = DiskStateLogger() 1183 self._disk.start() 1184 1185 1186 def publish(self): 1187 """Publishes results of various statistics gathered. 1188 1189 Returns: 1190 dict with 1191 key = string 'percent_<name>_<key>_time' 1192 value = float in percent 1193 """ 1194 results = {} 1195 tot_secs = kernel_trace.KernelTrace.uptime_secs() - \ 1196 self._start_uptime_secs 1197 for stat_obj in self._astats: 1198 percent_stats = stat_obj.refresh() 1199 logging.debug("pstats = %s", percent_stats) 1200 if stat_obj.name is 'gpu': 1201 # TODO(tbroch) remove this once GPU freq stats have proved 1202 # reliable 1203 stats_secs = sum(stat_obj._stats.itervalues()) 1204 if stats_secs < (tot_secs * 0.9) or \ 1205 stats_secs > (tot_secs * 1.1): 1206 logging.warning('%s stats dont look right. Not publishing.', 1207 stat_obj.name) 1208 continue 1209 new_res = {} 1210 AbstractStats.format_results_percent(new_res, stat_obj.name, 1211 percent_stats) 1212 wavg = stat_obj.weighted_average() 1213 if wavg: 1214 AbstractStats.format_results_wavg(new_res, stat_obj.name, wavg) 1215 1216 results.update(new_res) 1217 1218 new_res = {} 1219 if self._disk.get_error(): 1220 new_res['disk_logging_error'] = str(self._disk.get_error()) 1221 else: 1222 AbstractStats.format_results_percent(new_res, 'disk', 1223 self._disk.result()) 1224 results.update(new_res) 1225 1226 return results 1227 1228 1229class PowerMeasurement(object): 1230 """Class to measure power. 1231 1232 Public attributes: 1233 domain: String name of the power domain being measured. Example is 1234 'system' for total system power 1235 1236 Public methods: 1237 refresh: Performs any power/energy sampling and calculation and returns 1238 power as float in watts. This method MUST be implemented in 1239 subclass. 1240 """ 1241 1242 def __init__(self, domain): 1243 """Constructor.""" 1244 self.domain = domain 1245 1246 1247 def refresh(self): 1248 """Performs any power/energy sampling and calculation. 1249 1250 MUST be implemented in subclass 1251 1252 Returns: 1253 float, power in watts. 1254 """ 1255 raise NotImplementedError("'refresh' method should be implemented in " 1256 "subclass.") 1257 1258 1259def parse_power_supply_info(): 1260 """Parses power_supply_info command output. 1261 1262 Command output from power_manager ( tools/power_supply_info.cc ) looks like 1263 this: 1264 1265 Device: Line Power 1266 path: /sys/class/power_supply/cros_ec-charger 1267 ... 1268 Device: Battery 1269 path: /sys/class/power_supply/sbs-9-000b 1270 ... 1271 1272 """ 1273 rv = collections.defaultdict(dict) 1274 dev = None 1275 for ln in utils.system_output('power_supply_info').splitlines(): 1276 logging.debug("psu: %s", ln) 1277 result = re.findall(r'^Device:\s+(.*)', ln) 1278 if result: 1279 dev = result[0] 1280 continue 1281 result = re.findall(r'\s+(.+):\s+(.+)', ln) 1282 if result and dev: 1283 kname = re.findall(r'(.*)\s+\(\w+\)', result[0][0]) 1284 if kname: 1285 rv[dev][kname[0]] = result[0][1] 1286 else: 1287 rv[dev][result[0][0]] = result[0][1] 1288 1289 return rv 1290 1291 1292class SystemPower(PowerMeasurement): 1293 """Class to measure system power. 1294 1295 TODO(tbroch): This class provides a subset of functionality in BatteryStat 1296 in hopes of minimizing power draw. Investigate whether its really 1297 significant and if not, deprecate. 1298 1299 Private Attributes: 1300 _voltage_file: path to retrieve voltage in uvolts 1301 _current_file: path to retrieve current in uamps 1302 """ 1303 1304 def __init__(self, battery_dir): 1305 """Constructor. 1306 1307 Args: 1308 battery_dir: path to dir containing the files to probe and log. 1309 usually something like /sys/class/power_supply/BAT0/ 1310 """ 1311 super(SystemPower, self).__init__('system') 1312 # Files to log voltage and current from 1313 self._voltage_file = os.path.join(battery_dir, 'voltage_now') 1314 self._current_file = os.path.join(battery_dir, 'current_now') 1315 1316 1317 def refresh(self): 1318 """refresh method. 1319 1320 See superclass PowerMeasurement for details. 1321 """ 1322 keyvals = parse_power_supply_info() 1323 return float(keyvals['Battery']['energy rate']) 1324 1325 1326class MeasurementLogger(threading.Thread): 1327 """A thread that logs measurement readings. 1328 1329 Example code snippet: 1330 mylogger = MeasurementLogger([Measurent1, Measurent2]) 1331 mylogger.run() 1332 for testname in tests: 1333 start_time = time.time() 1334 #run the test method for testname 1335 mlogger.checkpoint(testname, start_time) 1336 keyvals = mylogger.calc() 1337 1338 Public attributes: 1339 seconds_period: float, probing interval in seconds. 1340 readings: list of lists of floats of measurements. 1341 times: list of floats of time (since Epoch) of when measurements 1342 occurred. len(time) == len(readings). 1343 done: flag to stop the logger. 1344 domains: list of domain strings being measured 1345 1346 Public methods: 1347 run: launches the thread to gather measuremnts 1348 calc: calculates 1349 save_results: 1350 1351 Private attributes: 1352 _measurements: list of Measurement objects to be sampled. 1353 _checkpoint_data: list of tuples. Tuple contains: 1354 tname: String of testname associated with this time interval 1355 tstart: Float of time when subtest started 1356 tend: Float of time when subtest ended 1357 _results: list of results tuples. Tuple contains: 1358 prefix: String of subtest 1359 mean: Float of mean in watts 1360 std: Float of standard deviation of measurements 1361 tstart: Float of time when subtest started 1362 tend: Float of time when subtest ended 1363 """ 1364 def __init__(self, measurements, seconds_period=1.0): 1365 """Initialize a logger. 1366 1367 Args: 1368 _measurements: list of Measurement objects to be sampled. 1369 seconds_period: float, probing interval in seconds. Default 1.0 1370 """ 1371 threading.Thread.__init__(self) 1372 1373 self.seconds_period = seconds_period 1374 1375 self.readings = [] 1376 self.times = [] 1377 self._checkpoint_data = [] 1378 1379 self.domains = [] 1380 self._measurements = measurements 1381 for meas in self._measurements: 1382 self.domains.append(meas.domain) 1383 1384 self.done = False 1385 1386 1387 def run(self): 1388 """Threads run method.""" 1389 while(not self.done): 1390 readings = [] 1391 for meas in self._measurements: 1392 readings.append(meas.refresh()) 1393 # TODO (dbasehore): We probably need proper locking in this file 1394 # since there have been race conditions with modifying and accessing 1395 # data. 1396 self.readings.append(readings) 1397 self.times.append(time.time()) 1398 time.sleep(self.seconds_period) 1399 1400 1401 def checkpoint(self, tname='', tstart=None, tend=None): 1402 """Check point the times in seconds associated with test tname. 1403 1404 Args: 1405 tname: String of testname associated with this time interval 1406 tstart: Float in seconds of when tname test started. Should be based 1407 off time.time() 1408 tend: Float in seconds of when tname test ended. Should be based 1409 off time.time(). If None, then value computed in the method. 1410 """ 1411 if not tstart and self.times: 1412 tstart = self.times[0] 1413 if not tend: 1414 tend = time.time() 1415 self._checkpoint_data.append((tname, tstart, tend)) 1416 logging.info('Finished test "%s" between timestamps [%s, %s]', 1417 tname, tstart, tend) 1418 1419 1420 def calc(self, mtype=None): 1421 """Calculate average measurement during each of the sub-tests. 1422 1423 Method performs the following steps: 1424 1. Signals the thread to stop running. 1425 2. Calculates mean, max, min, count on the samples for each of the 1426 measurements. 1427 3. Stores results to be written later. 1428 4. Creates keyvals for autotest publishing. 1429 1430 Args: 1431 mtype: string of measurement type. For example: 1432 pwr == power 1433 temp == temperature 1434 1435 Returns: 1436 dict of keyvals suitable for autotest results. 1437 """ 1438 if not mtype: 1439 mtype = 'meas' 1440 1441 t = numpy.array(self.times) 1442 keyvals = {} 1443 results = [] 1444 1445 if not self.done: 1446 self.done = True 1447 # times 2 the sleep time in order to allow for readings as well. 1448 self.join(timeout=self.seconds_period * 2) 1449 1450 if not self._checkpoint_data: 1451 self.checkpoint() 1452 1453 for i, domain_readings in enumerate(zip(*self.readings)): 1454 meas = numpy.array(domain_readings) 1455 domain = self.domains[i] 1456 1457 for tname, tstart, tend in self._checkpoint_data: 1458 if tname: 1459 prefix = '%s_%s' % (tname, domain) 1460 else: 1461 prefix = domain 1462 keyvals[prefix+'_duration'] = tend - tstart 1463 # Select all readings taken between tstart and tend timestamps. 1464 # Try block just in case 1465 # code.google.com/p/chromium/issues/detail?id=318892 1466 # is not fixed. 1467 try: 1468 meas_array = meas[numpy.bitwise_and(tstart < t, t < tend)] 1469 except ValueError, e: 1470 logging.debug('Error logging measurements: %s', str(e)) 1471 logging.debug('timestamps %d %s' % (t.len, t)) 1472 logging.debug('timestamp start, end %f %f' % (tstart, tend)) 1473 logging.debug('measurements %d %s' % (meas.len, meas)) 1474 1475 # If sub-test terminated early, avoid calculating avg, std and 1476 # min 1477 if not meas_array.size: 1478 continue 1479 meas_mean = meas_array.mean() 1480 meas_std = meas_array.std() 1481 1482 # Results list can be used for pretty printing and saving as csv 1483 results.append((prefix, meas_mean, meas_std, 1484 tend - tstart, tstart, tend)) 1485 1486 keyvals[prefix + '_' + mtype] = meas_mean 1487 keyvals[prefix + '_' + mtype + '_cnt'] = meas_array.size 1488 keyvals[prefix + '_' + mtype + '_max'] = meas_array.max() 1489 keyvals[prefix + '_' + mtype + '_min'] = meas_array.min() 1490 keyvals[prefix + '_' + mtype + '_std'] = meas_std 1491 1492 self._results = results 1493 return keyvals 1494 1495 1496 def save_results(self, resultsdir, fname=None): 1497 """Save computed results in a nice tab-separated format. 1498 This is useful for long manual runs. 1499 1500 Args: 1501 resultsdir: String, directory to write results to 1502 fname: String name of file to write results to 1503 """ 1504 if not fname: 1505 fname = 'meas_results_%.0f.txt' % time.time() 1506 fname = os.path.join(resultsdir, fname) 1507 with file(fname, 'wt') as f: 1508 for row in self._results: 1509 # First column is name, the rest are numbers. See _calc_power() 1510 fmt_row = [row[0]] + ['%.2f' % x for x in row[1:]] 1511 line = '\t'.join(fmt_row) 1512 f.write(line + '\n') 1513 1514 1515class PowerLogger(MeasurementLogger): 1516 def save_results(self, resultsdir, fname=None): 1517 if not fname: 1518 fname = 'power_results_%.0f.txt' % time.time() 1519 super(PowerLogger, self).save_results(resultsdir, fname) 1520 1521 1522 def calc(self, mtype='pwr'): 1523 return super(PowerLogger, self).calc(mtype) 1524 1525 1526class TempMeasurement(object): 1527 """Class to measure temperature. 1528 1529 Public attributes: 1530 domain: String name of the temperature domain being measured. Example is 1531 'cpu' for cpu temperature 1532 1533 Private attributes: 1534 _path: Path to temperature file to read ( in millidegrees Celsius ) 1535 1536 Public methods: 1537 refresh: Performs any temperature sampling and calculation and returns 1538 temperature as float in degrees Celsius. 1539 """ 1540 def __init__(self, domain, path): 1541 """Constructor.""" 1542 self.domain = domain 1543 self._path = path 1544 1545 1546 def refresh(self): 1547 """Performs temperature 1548 1549 Returns: 1550 float, temperature in degrees Celsius 1551 """ 1552 return int(utils.read_one_line(self._path)) / 1000. 1553 1554 1555class TempLogger(MeasurementLogger): 1556 """A thread that logs temperature readings in millidegrees Celsius.""" 1557 def __init__(self, measurements, seconds_period=30.0): 1558 if not measurements: 1559 measurements = [] 1560 tstats = ThermalStatHwmon() 1561 for kname in tstats.fields: 1562 match = re.match(r'(\S+)_temp(\d+)_input', kname) 1563 if not match: 1564 continue 1565 domain = match.group(1) + '-t' + match.group(2) 1566 fpath = tstats.fields[kname][0] 1567 new_meas = TempMeasurement(domain, fpath) 1568 measurements.append(new_meas) 1569 super(TempLogger, self).__init__(measurements, seconds_period) 1570 1571 1572 def save_results(self, resultsdir, fname=None): 1573 if not fname: 1574 fname = 'temp_results_%.0f.txt' % time.time() 1575 super(TempLogger, self).save_results(resultsdir, fname) 1576 1577 1578 def calc(self, mtype='temp'): 1579 return super(TempLogger, self).calc(mtype) 1580 1581 1582class DiskStateLogger(threading.Thread): 1583 """Records the time percentages the disk stays in its different power modes. 1584 1585 Example code snippet: 1586 mylogger = power_status.DiskStateLogger() 1587 mylogger.start() 1588 result = mylogger.result() 1589 1590 Public methods: 1591 start: Launches the thread and starts measurements. 1592 result: Stops the thread if it's still running and returns measurements. 1593 get_error: Returns the exception in _error if it exists. 1594 1595 Private functions: 1596 _get_disk_state: Returns the disk's current ATA power mode as a string. 1597 1598 Private attributes: 1599 _seconds_period: Disk polling interval in seconds. 1600 _stats: Dict that maps disk states to seconds spent in them. 1601 _running: Flag that is True as long as the logger should keep running. 1602 _time: Timestamp of last disk state reading. 1603 _device_path: The file system path of the disk's device node. 1604 _error: Contains a TestError exception if an unexpected error occured 1605 """ 1606 def __init__(self, seconds_period = 5.0, device_path = None): 1607 """Initializes a logger. 1608 1609 Args: 1610 seconds_period: Disk polling interval in seconds. Default 5.0 1611 device_path: The path of the disk's device node. Default '/dev/sda' 1612 """ 1613 threading.Thread.__init__(self) 1614 self._seconds_period = seconds_period 1615 self._device_path = device_path 1616 self._stats = {} 1617 self._running = False 1618 self._error = None 1619 1620 result = utils.system_output('rootdev -s') 1621 # TODO(tbroch) Won't work for emmc storage and will throw this error in 1622 # keyvals : 'ioctl(SG_IO) error: [Errno 22] Invalid argument' 1623 # Lets implement something complimentary for emmc 1624 if not device_path: 1625 self._device_path = \ 1626 re.sub('(sd[a-z]|mmcblk[0-9]+)p?[0-9]+', '\\1', result) 1627 logging.debug("device_path = %s", self._device_path) 1628 1629 1630 def start(self): 1631 logging.debug("inside DiskStateLogger.start") 1632 if os.path.exists(self._device_path): 1633 logging.debug("DiskStateLogger started") 1634 super(DiskStateLogger, self).start() 1635 1636 1637 def _get_disk_state(self): 1638 """Checks the disk's power mode and returns it as a string. 1639 1640 This uses the SG_IO ioctl to issue a raw SCSI command data block with 1641 the ATA-PASS-THROUGH command that allows SCSI-to-ATA translation (see 1642 T10 document 04-262r8). The ATA command issued is CHECKPOWERMODE1, 1643 which returns the device's current power mode. 1644 """ 1645 1646 def _addressof(obj): 1647 """Shortcut to return the memory address of an object as integer.""" 1648 return ctypes.cast(obj, ctypes.c_void_p).value 1649 1650 scsi_cdb = struct.pack("12B", # SCSI command data block (uint8[12]) 1651 0xa1, # SCSI opcode: ATA-PASS-THROUGH 1652 3 << 1, # protocol: Non-data 1653 1 << 5, # flags: CK_COND 1654 0, # features 1655 0, # sector count 1656 0, 0, 0, # LBA 1657 1 << 6, # flags: ATA-USING-LBA 1658 0xe5, # ATA opcode: CHECKPOWERMODE1 1659 0, # reserved 1660 0, # control (no idea what this is...) 1661 ) 1662 scsi_sense = (ctypes.c_ubyte * 32)() # SCSI sense buffer (uint8[32]) 1663 sgio_header = struct.pack("iiBBHIPPPIIiPBBBBHHiII", # see <scsi/sg.h> 1664 83, # Interface ID magic number (int32) 1665 -1, # data transfer direction: none (int32) 1666 12, # SCSI command data block length (uint8) 1667 32, # SCSI sense data block length (uint8) 1668 0, # iovec_count (not applicable?) (uint16) 1669 0, # data transfer length (uint32) 1670 0, # data block pointer 1671 _addressof(scsi_cdb), # SCSI CDB pointer 1672 _addressof(scsi_sense), # sense buffer pointer 1673 500, # timeout in milliseconds (uint32) 1674 0, # flags (uint32) 1675 0, # pack ID (unused) (int32) 1676 0, # user data pointer (unused) 1677 0, 0, 0, 0, 0, 0, 0, 0, 0, # output params 1678 ) 1679 try: 1680 with open(self._device_path, 'r') as dev: 1681 result = fcntl.ioctl(dev, 0x2285, sgio_header) 1682 except IOError, e: 1683 raise error.TestError('ioctl(SG_IO) error: %s' % str(e)) 1684 _, _, _, _, status, host_status, driver_status = \ 1685 struct.unpack("4x4xxx2x4xPPP4x4x4xPBxxxHH4x4x4x", result) 1686 if status != 0x2: # status: CHECK_CONDITION 1687 raise error.TestError('SG_IO status: %d' % status) 1688 if host_status != 0: 1689 raise error.TestError('SG_IO host status: %d' % host_status) 1690 if driver_status != 0x8: # driver status: SENSE 1691 raise error.TestError('SG_IO driver status: %d' % driver_status) 1692 1693 if scsi_sense[0] != 0x72: # resp. code: current error, descriptor format 1694 raise error.TestError('SENSE response code: %d' % scsi_sense[0]) 1695 if scsi_sense[1] != 0: # sense key: No Sense 1696 raise error.TestError('SENSE key: %d' % scsi_sense[1]) 1697 if scsi_sense[7] < 14: # additional length (ATA status is 14 - 1 bytes) 1698 raise error.TestError('ADD. SENSE too short: %d' % scsi_sense[7]) 1699 if scsi_sense[8] != 0x9: # additional descriptor type: ATA Return Status 1700 raise error.TestError('SENSE descriptor type: %d' % scsi_sense[8]) 1701 if scsi_sense[11] != 0: # errors: none 1702 raise error.TestError('ATA error code: %d' % scsi_sense[11]) 1703 1704 if scsi_sense[13] == 0x00: 1705 return 'standby' 1706 if scsi_sense[13] == 0x80: 1707 return 'idle' 1708 if scsi_sense[13] == 0xff: 1709 return 'active' 1710 return 'unknown(%d)' % scsi_sense[13] 1711 1712 1713 def run(self): 1714 """The Thread's run method.""" 1715 try: 1716 self._time = time.time() 1717 self._running = True 1718 while(self._running): 1719 time.sleep(self._seconds_period) 1720 state = self._get_disk_state() 1721 new_time = time.time() 1722 if state in self._stats: 1723 self._stats[state] += new_time - self._time 1724 else: 1725 self._stats[state] = new_time - self._time 1726 self._time = new_time 1727 except error.TestError, e: 1728 self._error = e 1729 self._running = False 1730 1731 1732 def result(self): 1733 """Stop the logger and return dict with result percentages.""" 1734 if (self._running): 1735 self._running = False 1736 self.join(self._seconds_period * 2) 1737 return AbstractStats.to_percent(self._stats) 1738 1739 1740 def get_error(self): 1741 """Returns the _error exception... please only call after result().""" 1742 return self._error 1743 1744def parse_reef_s0ix_residency_info(): 1745 """ 1746 Parses the ioss_info file which contains the S0ix residency counter 1747 on reef variants. 1748 Example file : 1749 -------------------------------------- 1750 I0SS TELEMETRY EVENTLOG 1751 -------------------------------------- 1752 SOC_S0IX_TOTAL_RES 0xd241b68 1753 1754 @returns Residency(secs) for Reef platform. 1755 @raises TestError if the debugfs file for this 1756 specific board is not found or if S0ix residency info is not 1757 found in the debugfs file. 1758 """ 1759 1760 ioss_info_path = '/sys/kernel/debug/telemetry/ioss_info' 1761 S0IX_CLOCK_HZ = 19.2e6 1762 if not os.path.exists(ioss_info_path): 1763 raise error.TestNAError('File: ' + ioss_info_path + ' used to' 1764 ' measure s0ix residency does not exist') 1765 1766 with open(ioss_info_path) as fd: 1767 residency = -1 1768 for line in fd: 1769 if line.startswith('SOC_S0IX_TOTAL_RES'): 1770 #residency here is a clock pulse with XTAL of 19.2mhz. 1771 residency = int(line.rsplit(None, 1)[-1], 0) 1772 logging.debug("S0ix Residency: %d", residency) 1773 # Helps in debugging scenarios where the residency count has not increased. 1774 elif 'BLOCK' in line: 1775 logging.debug(line) 1776 if residency is not -1: 1777 return residency / S0IX_CLOCK_HZ 1778 raise error.TestNAError('Could not find s0ix residency in ' + 1779 ioss_info_path) 1780 1781 1782class S0ixResidencyStats(object): 1783 """ 1784 Measures the S0ix residency of a given board over time. Since 1785 the debugfs path and the format of the file with the information 1786 about S0ix residency might differ for every platform, we have a platform 1787 specific parser. 1788 """ 1789 S0IX_PARSERS_PER_PLATFORM = { 1790 'Google_Reef' : parse_reef_s0ix_residency_info, 1791 } 1792 1793 def __init__(self): 1794 try: 1795 current_plat = utils.run('mosys platform family', 1796 verbose=False).stdout.strip() 1797 except error.CmdError: 1798 raise error.TestNAError('Could not find the platform family.') 1799 if current_plat not in self.S0IX_PARSERS_PER_PLATFORM: 1800 raise error.TestNAError('No Residency counter parser for' + 1801 ' the board: ' + current_plat) 1802 self._parse_function = \ 1803 self.S0IX_PARSERS_PER_PLATFORM[current_plat] 1804 self._initial_residency = self._parse_function() 1805 1806 def get_accumulated_residency_secs(self): 1807 """ 1808 @returns S0ix Residency since the class has been initialized. 1809 """ 1810 return self._parse_function() - self._initial_residency 1811