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