1# Lint as: python2, python3 2# Copyright 2018 The Chromium OS Authors. All rights reserved. 3# Use of this source code is governed by a BSD-style license that can be 4# found in the LICENSE file. 5import logging 6import re 7import time 8 9from autotest_lib.client.bin import test 10from autotest_lib.client.bin import utils 11from autotest_lib.client.common_lib import error 12from autotest_lib.client.common_lib.cros import arc_common 13from autotest_lib.client.common_lib.cros import retry 14from autotest_lib.client.common_lib.cros.network import interface 15from autotest_lib.client.cros import service_stopper 16from autotest_lib.client.cros.camera import camera_utils 17from autotest_lib.client.cros.power import force_discharge_utils 18from autotest_lib.client.cros.power import power_dashboard 19from autotest_lib.client.cros.power import power_status 20from autotest_lib.client.cros.power import power_telemetry_utils 21from autotest_lib.client.cros.power import power_utils 22from autotest_lib.client.cros.video import histogram_verifier 23 24class power_Test(test.test): 25 """Optional base class power related tests.""" 26 version = 1 27 28 keypress_histogram = 'Event.Latency.EndToEnd.KeyPress' 29 histogram_re = 'Histogram: %s recorded (\d+) samples, mean = (\d+\.\d+)' 30 hist_percentile_re = '^(\d+).+\{(\d+)\.\d+\%\}' 31 32 def initialize(self, 33 seconds_period=20., 34 pdash_note='', 35 force_discharge='false', 36 check_network=False, 37 run_arc=True): 38 """Perform necessary initialization prior to power test run. 39 40 @param seconds_period: float of probing interval in seconds. 41 @param pdash_note: note of the current run to send to power dashboard. 42 @param force_discharge: string of whether to tell ec to discharge 43 battery even when the charger is plugged in. 'false' means no 44 forcing discharge; 'true' means forcing discharge and raising an 45 error when it fails; 'optional' means forcing discharge when 46 possible but not raising an error when it fails, which is more 47 friendly to devices without a battery. 48 @param check_network: check that Ethernet interface is not running. 49 @param run_arc: bool, whether to run with ARC (if available) 50 51 @var backlight: power_utils.Backlight object. 52 @var keyvals: dictionary of result keyvals. 53 @var status: power_status.SysStat object. 54 55 @var _checkpoint_logger: power_status.CheckpointLogger to track 56 checkpoint data. 57 @var _psr: power_utils.DisplayPanelSelfRefresh object to monitor PSR. 58 @var _services: service_stopper.ServiceStopper object. 59 @var _start_time: float of time in seconds since Epoch test started. 60 @var _stats: power_status.StatoMatic object. 61 @var _meas_logs: list of power_status.MeasurementLoggers 62 """ 63 super(power_Test, self).initialize() 64 self.keyvals = dict() 65 self.status = power_status.get_status() 66 67 self._checkpoint_logger = power_status.CheckpointLogger() 68 self._seconds_period = seconds_period 69 70 self._force_discharge_success = force_discharge_utils.process( 71 force_discharge, self.status) 72 self.backlight = power_utils.Backlight( 73 force_battery=self._force_discharge_success) 74 self.backlight.set_default() 75 76 ifaces = [iface for iface in interface.get_interfaces() 77 if (not iface.is_wifi_device() and 78 iface.name.startswith('eth'))] 79 logging.debug('Ethernet interfaces include: %s', 80 str([iface.name for iface in ifaces])) 81 for iface in ifaces: 82 if check_network and iface.is_lower_up: 83 raise error.TestError('Ethernet interface is active. ' 84 'Please remove Ethernet cable.') 85 86 self._psr = power_utils.DisplayPanelSelfRefresh() 87 self._services = service_stopper.ServiceStopper( 88 service_stopper.ServiceStopper.POWER_DRAW_SERVICES) 89 self._services.stop_services() 90 self._stats = power_status.StatoMatic() 91 92 self._meas_logs = power_status.create_measurement_loggers( 93 seconds_period, self._checkpoint_logger) 94 logging.debug('measurement loggers (%d):', len(self._meas_logs)) 95 for log in self._meas_logs: 96 logging.debug('%s: %s', type(log).__name__, ", ".join(log.domains)) 97 98 self._pdash_note = pdash_note 99 self._failure_messages = [] 100 101 self._arc_mode = arc_common.ARC_MODE_DISABLED 102 if run_arc and utils.is_arc_available(): 103 self._arc_mode = arc_common.ARC_MODE_ENABLED 104 self.keyvals['arc_mode'] = self._arc_mode 105 106 def get_extra_browser_args_for_camera_test(self): 107 """Return Chrome args for camera power test.""" 108 ret = [ 109 # No pop up to ask permission to record video. 110 '--use-fake-ui-for-media-stream', 111 # Allow 2 windows side by side. 112 '--force-tablet-mode=clamshell', 113 # Prefer using constant frame rate for camera streaming. 114 '--enable-features=PreferConstantFrameRate', 115 # Bypass HID detection for Chromebox / Chromebase. 116 '--disable-hid-detection-on-oobe', 117 # Disable test account info sync, eg. Wi-Fi credentials, 118 # so that each test run does not remember info from last test 119 # run. 120 '--disable-sync' 121 ] 122 123 # Use fake camera for DUT without camera, e.g. chromebox. 124 if not camera_utils.has_builtin_or_vivid_camera(): 125 ret.append('--use-fake-device-for-media-stream') 126 self.keyvals['use_fake_camera'] = 1 127 else: 128 self.keyvals['use_fake_camera'] = 0 129 return ret 130 131 def warmup(self, warmup_time=30): 132 """Warm up. 133 134 Wait between initialization and run_once for new settings to stabilize. 135 136 @param warmup_time: integer of seconds to warmup. 137 """ 138 time.sleep(warmup_time) 139 140 def start_measurements(self): 141 """Start measurements.""" 142 for log in self._meas_logs: 143 log.start() 144 self._start_time = time.time() 145 if self.status.battery: 146 self._start_energy = self.status.battery.energy 147 self._keyvallogger = power_dashboard.KeyvalLogger(self._start_time) 148 power_telemetry_utils.start_measurement() 149 150 def loop_sleep(self, loop, sleep_secs): 151 """Jitter free sleep. 152 153 @param loop: integer of loop (1st is zero). 154 @param sleep_secs: integer of desired sleep seconds. 155 """ 156 next_time = self._start_time + (loop + 1) * sleep_secs 157 time.sleep(next_time - time.time()) 158 159 def checkpoint_measurements(self, name, start_time=None): 160 """Checkpoint measurements. 161 162 @param name: string name of measurement being checkpointed. 163 @param start_time: float of time in seconds since Epoch that 164 measurements being checkpointed began. 165 """ 166 if not start_time: 167 start_time = self._start_time 168 self.status.refresh() 169 self._checkpoint_logger.checkpoint(name, start_time) 170 self._psr.refresh() 171 172 @retry.retry(Exception, timeout_min=1, delay_sec=2) 173 def collect_keypress_latency(self, cr): 174 """Collect keypress latency information from Histograms. 175 176 @param cr: object, the Chrome instance 177 """ 178 179 keypress_histogram_end = histogram_verifier.get_histogram( 180 cr, self.keypress_histogram) 181 matches = re.search((self.histogram_re % self.keypress_histogram), 182 keypress_histogram_end) 183 184 if matches: 185 count = int(matches.group(1)) 186 mean_latency = float(matches.group(2)) 187 logging.info('latency count %d mean %f', count, mean_latency) 188 self.keyvals['keypress_cnt'] = count 189 self.keyvals['keypress_latency_us_avg'] = mean_latency 190 self.output_perf_value(description='keypress_cnt', value=count, 191 higher_is_better=True) 192 self.output_perf_value(description='keypress_latency_us_avg', 193 value=mean_latency, 194 higher_is_better=False) 195 self._keyvallogger.add_item('keypress_cnt', count, 'point', 196 'keypress') 197 self._keyvallogger.add_item('keypress_latency_us_avg', 198 mean_latency, 'point', 'keypress') 199 200 # Capture the first bucket >= 90th percentile 201 for s in keypress_histogram_end.splitlines(): 202 matches = re.search((self.hist_percentile_re), s) 203 if matches: 204 lat = int(matches.group(1)) 205 perc = int(matches.group(2)) 206 if perc >= 90: 207 self.keyvals['keypress_latency_us_high'] = lat 208 self.keyvals['keypress_high_percentile'] = perc 209 self.output_perf_value( 210 description='keypress_latency_us_high', value=lat, 211 higher_is_better=False) 212 self.output_perf_value( 213 description='keypress_high_percentile', value=perc, 214 higher_is_better=False) 215 self._keyvallogger.add_item('keypress_latency_us_high', 216 lat, 'point', 'keypress') 217 self._keyvallogger.add_item('keypress_high_percentile', 218 perc, 'point', 'keypress') 219 break 220 221 def publish_keyvals(self): 222 """Publish power result keyvals.""" 223 keyvals = self._stats.publish() 224 keyvals['level_backlight_max'] = self.backlight.get_max_level() 225 keyvals['level_backlight_current'] = self.backlight.get_level() 226 227 # record battery stats if battery exists 228 keyvals['b_on_ac'] = int(not self._force_discharge_success 229 and self.status.on_ac()) 230 keyvals['force_discharge'] = int(self._force_discharge_success) 231 for key in [ 232 'b_on_ac', 'force_discharge', 'percent_usb_suspended_time' 233 ]: 234 self._keyvallogger.add_item(key, keyvals[key], 'point', 'perf') 235 236 if self.status.battery: 237 keyvals['ah_charge_full'] = self.status.battery.charge_full 238 keyvals['ah_charge_full_design'] = \ 239 self.status.battery.charge_full_design 240 keyvals['ah_charge_now'] = self.status.battery.charge_now 241 keyvals['a_current_now'] = self.status.battery.current_now 242 243 keyvals['wh_energy_full'] = self.status.battery.energy_full 244 keyvals['wh_energy_full_design'] = \ 245 self.status.battery.energy_full_design 246 keyvals['wh_energy_now'] = self.status.battery.energy 247 keyvals['wh_energy_start'] = self._start_energy 248 energy_used = self._start_energy - self.status.battery.energy 249 runtime_minutes = (time.time() - self._start_time) / 60. 250 keyvals['wh_energy_used'] = energy_used 251 keyvals['minutes_tested'] = runtime_minutes 252 self._keyvallogger.add_item('minutes_tested', 253 keyvals['minutes_tested'], 'point', 254 'perf') 255 256 low_batt = power_utils.get_low_battery_shutdown_percent() 257 keyvals['percent_sys_low_battery'] = low_batt 258 259 if energy_used > 0 and runtime_minutes > 1: 260 keyvals['w_energy_rate'] = energy_used * 60. / runtime_minutes 261 self._keyvallogger.add_item('w_energy_rate', 262 keyvals['w_energy_rate'], 'point', 263 'perf') 264 energy_avail = self.status.battery.energy_full_design * \ 265 ((100. - low_batt) / 100.) 266 keyvals['minutes_battery_life'] = energy_avail / energy_used * \ 267 runtime_minutes 268 self._keyvallogger.add_item('minutes_battery_life', 269 keyvals['minutes_battery_life'], 270 'point', 'perf') 271 keyvals['hours_battery_life'] = \ 272 keyvals['minutes_battery_life'] / 60. 273 self._keyvallogger.add_item('hours_battery_life', 274 keyvals['hours_battery_life'], 275 'point', 'perf') 276 277 keyvals['v_voltage_min_design'] = \ 278 self.status.battery.voltage_min_design 279 keyvals['v_voltage_now'] = self.status.battery.voltage_now 280 281 for log in self._meas_logs: 282 keyvals.update(log.calc()) 283 keyvals.update(self._psr.get_keyvals()) 284 285 self.keyvals.update(keyvals) 286 287 core_keyvals = power_utils.get_core_keyvals(self.keyvals) 288 self.write_perf_keyval(core_keyvals) 289 290 def publish_dashboard(self): 291 """Report results to chromeperf & power dashboard.""" 292 293 self.publish_keyvals() 294 295 # publish power values 296 for key, values in self.keyvals.items(): 297 if key.endswith('pwr_avg'): 298 self.output_perf_value(description=key, value=values, units='W', 299 higher_is_better=False, graph='power') 300 301 # publish temperature values 302 for key, values in self.keyvals.items(): 303 if key.endswith('temp_avg'): 304 self.output_perf_value(description=key, value=values, units='C', 305 higher_is_better=False, graph='temperature') 306 307 # publish fps values 308 for key, values in self.keyvals.items(): 309 if key.endswith('fps_avg'): 310 self.output_perf_value(description=key, value=values, 311 units='fps', higher_is_better=True, graph='fps') 312 313 # include KeyvalLogger in dashboard 314 self._meas_logs.append(self._keyvallogger) 315 316 # publish to power dashboard 317 dashboard_factory = power_dashboard.get_dashboard_factory() 318 for log in self._meas_logs: 319 dashboard = dashboard_factory.createDashboard(log, 320 self.tagged_testname, self.resultsdir, note=self._pdash_note) 321 dashboard.upload() 322 323 def _save_results(self): 324 """Save results of each logger in resultsdir.""" 325 for log in self._meas_logs: 326 log.save_results(self.resultsdir) 327 self._checkpoint_logger.save_checkpoint_data(self.resultsdir) 328 329 def postprocess_iteration(self): 330 """Write keyval and send data to dashboard.""" 331 power_telemetry_utils.end_measurement() 332 self.status.refresh() 333 for log in self._meas_logs: 334 log.done = True 335 super(power_Test, self).postprocess_iteration() 336 self.publish_dashboard() 337 self._save_results() 338 power_dashboard.generate_parallax_report(self.outputdir) 339 if self._failure_messages: 340 raise error.TestFail('Test has failed with messages: %s' % 341 self._failure_messages) 342 343 def cleanup(self): 344 """Reverse setting change in initialization.""" 345 force_discharge_utils.restore(self._force_discharge_success) 346 if self.backlight: 347 self.backlight.restore() 348 self._services.restore_services() 349 super(power_Test, self).cleanup() 350