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