Home | History | Annotate | Download | only in power_LoadTest
      1 # Copyright (c) 2012 The Chromium OS Authors. All rights reserved.
      2 # Use of this source code is governed by a BSD-style license that can be
      3 # found in the LICENSE file.
      4 
      5 import collections
      6 import logging
      7 import numpy
      8 import os
      9 import time
     10 
     11 from autotest_lib.client.bin import utils
     12 from autotest_lib.client.common_lib import error
     13 from autotest_lib.client.common_lib.cros import arc
     14 from autotest_lib.client.common_lib.cros import arc_common
     15 from autotest_lib.client.common_lib.cros import chrome
     16 from autotest_lib.client.common_lib.cros import power_load_util
     17 from autotest_lib.client.common_lib.cros.network import interface
     18 from autotest_lib.client.common_lib.cros.network import xmlrpc_datatypes
     19 from autotest_lib.client.common_lib.cros.network import xmlrpc_security_types
     20 from autotest_lib.client.cros import backchannel, httpd
     21 from autotest_lib.client.cros import memory_bandwidth_logger
     22 from autotest_lib.client.cros import service_stopper
     23 from autotest_lib.client.cros.audio import audio_helper
     24 from autotest_lib.client.cros.networking import wifi_proxy
     25 from autotest_lib.client.cros.power import power_dashboard
     26 from autotest_lib.client.cros.power import power_rapl
     27 from autotest_lib.client.cros.power import power_status
     28 from autotest_lib.client.cros.power import power_utils
     29 from telemetry.core import exceptions
     30 
     31 params_dict = {
     32     'test_time_ms': '_mseconds',
     33     'should_scroll': '_should_scroll',
     34     'should_scroll_up': '_should_scroll_up',
     35     'scroll_loop': '_scroll_loop',
     36     'scroll_interval_ms': '_scroll_interval_ms',
     37     'scroll_by_pixels': '_scroll_by_pixels',
     38     'tasks': '_tasks',
     39 }
     40 
     41 class power_LoadTest(arc.ArcTest):
     42     """test class"""
     43     version = 2
     44 
     45     def initialize(self, percent_initial_charge_min=None,
     46                  check_network=True, loop_time=3600, loop_count=1,
     47                  should_scroll='true', should_scroll_up='true',
     48                  scroll_loop='false', scroll_interval_ms='10000',
     49                  scroll_by_pixels='600', test_low_batt_p=3,
     50                  verbose=True, force_wifi=False, wifi_ap='', wifi_sec='none',
     51                  wifi_pw='', wifi_timeout=60, tasks='',
     52                  volume_level=10, mic_gain=10, low_batt_margin_p=2,
     53                  ac_ok=False, log_mem_bandwidth=False, gaia_login=True):
     54         """
     55         percent_initial_charge_min: min battery charge at start of test
     56         check_network: check that Ethernet interface is not running
     57         loop_time: length of time to run the test for in each loop
     58         loop_count: number of times to loop the test for
     59         should_scroll: should the extension scroll pages
     60         should_scroll_up: should scroll in up direction
     61         scroll_loop: continue scrolling indefinitely
     62         scroll_interval_ms: how often to scoll
     63         scroll_by_pixels: number of pixels to scroll each time
     64         test_low_batt_p: percent battery at which test should stop
     65         verbose: add more logging information
     66         force_wifi: should we force to test to run on wifi
     67         wifi_ap: the name (ssid) of the wifi access point
     68         wifi_sec: the type of security for the wifi ap
     69         wifi_pw: password for the wifi ap
     70         wifi_timeout: The timeout for wifi configuration
     71         volume_level: percent audio volume level
     72         mic_gain: percent audio microphone gain level
     73         low_batt_margin_p: percent low battery margin to be added to
     74             sys_low_batt_p to guarantee test completes prior to powerd shutdown
     75         ac_ok: boolean to allow running on AC
     76         log_mem_bandwidth: boolean to log memory bandwidth during the test
     77         gaia_login: boolean of whether real GAIA login should be attempted.
     78         """
     79         self._backlight = None
     80         self._services = None
     81         self._browser = None
     82         self._loop_time = loop_time
     83         self._loop_count = loop_count
     84         self._mseconds = self._loop_time * 1000
     85         self._verbose = verbose
     86 
     87         self._sys_low_batt_p = 0.
     88         self._sys_low_batt_s = 0.
     89         self._test_low_batt_p = test_low_batt_p
     90         self._should_scroll = should_scroll
     91         self._should_scroll_up = should_scroll_up
     92         self._scroll_loop = scroll_loop
     93         self._scroll_interval_ms = scroll_interval_ms
     94         self._scroll_by_pixels = scroll_by_pixels
     95         self._tmp_keyvals = {}
     96         self._power_status = None
     97         self._force_wifi = force_wifi
     98         self._testServer = None
     99         self._tasks = tasks.replace(' ','')
    100         self._backchannel = None
    101         self._shill_proxy = None
    102         self._volume_level = volume_level
    103         self._mic_gain = mic_gain
    104         self._ac_ok = ac_ok
    105         self._log_mem_bandwidth = log_mem_bandwidth
    106         self._wait_time = 60
    107         self._stats = collections.defaultdict(list)
    108         self._gaia_login = gaia_login
    109 
    110         if not power_utils.has_battery():
    111             if ac_ok and (power_utils.has_powercap_support() or
    112                           power_utils.has_rapl_support()):
    113                 logging.info("Device has no battery but has powercap data.")
    114             else:
    115                 rsp = "Skipping test for device without battery and powercap."
    116                 raise error.TestNAError(rsp)
    117         self._power_status = power_status.get_status()
    118         self._tmp_keyvals['b_on_ac'] = self._power_status.on_ac()
    119 
    120         self._username = power_load_util.get_username()
    121         self._password = power_load_util.get_password()
    122 
    123         if not ac_ok:
    124             self._power_status.assert_battery_state(percent_initial_charge_min)
    125         # If force wifi enabled, convert eth0 to backchannel and connect to the
    126         # specified WiFi AP.
    127         if self._force_wifi:
    128             sec_config = None
    129             # TODO(dbasehore): Fix this when we get a better way of figuring out
    130             # the wifi security configuration.
    131             if wifi_sec == 'rsn' or wifi_sec == 'wpa':
    132                 sec_config = xmlrpc_security_types.WPAConfig(
    133                         psk=wifi_pw,
    134                         wpa_mode=xmlrpc_security_types.WPAConfig.MODE_PURE_WPA2,
    135                         wpa2_ciphers=
    136                                 [xmlrpc_security_types.WPAConfig.CIPHER_CCMP])
    137             wifi_config = xmlrpc_datatypes.AssociationParameters(
    138                     ssid=wifi_ap, security_config=sec_config,
    139                     configuration_timeout=wifi_timeout)
    140             # If backchannel is already running, don't run it again.
    141             self._backchannel = backchannel.Backchannel()
    142             if not self._backchannel.setup():
    143                 raise error.TestError('Could not setup Backchannel network.')
    144 
    145             self._shill_proxy = wifi_proxy.WifiProxy()
    146             self._shill_proxy.remove_all_wifi_entries()
    147             for i in xrange(1,4):
    148                 raw_output = self._shill_proxy.connect_to_wifi_network(
    149                         wifi_config.ssid,
    150                         wifi_config.security,
    151                         wifi_config.security_parameters,
    152                         wifi_config.save_credentials,
    153                         station_type=wifi_config.station_type,
    154                         hidden_network=wifi_config.is_hidden,
    155                         discovery_timeout_seconds=
    156                                 wifi_config.discovery_timeout,
    157                         association_timeout_seconds=
    158                                 wifi_config.association_timeout,
    159                         configuration_timeout_seconds=
    160                                 wifi_config.configuration_timeout * i)
    161                 result = xmlrpc_datatypes.AssociationResult. \
    162                         from_dbus_proxy_output(raw_output)
    163                 if result.success:
    164                     break
    165                 logging.warn('wifi connect: disc:%d assoc:%d config:%d fail:%s',
    166                              result.discovery_time, result.association_time,
    167                              result.configuration_time, result.failure_reason)
    168             else:
    169                 raise error.TestError('Could not connect to WiFi network.')
    170 
    171         else:
    172             # Find all wired ethernet interfaces.
    173             ifaces = [ iface for iface in interface.get_interfaces()
    174                 if (not iface.is_wifi_device() and
    175                     iface.name.find('eth') != -1) ]
    176             logging.debug(str([iface.name for iface in ifaces]))
    177             for iface in ifaces:
    178                 if check_network and iface.is_lower_up:
    179                     raise error.TestError('Ethernet interface is active. ' +
    180                                           'Please remove Ethernet cable')
    181 
    182         # record the max backlight level
    183         self._backlight = power_utils.Backlight()
    184         self._tmp_keyvals['level_backlight_max'] = \
    185             self._backlight.get_max_level()
    186 
    187         self._services = service_stopper.ServiceStopper(
    188             service_stopper.ServiceStopper.POWER_DRAW_SERVICES)
    189         self._services.stop_services()
    190 
    191         # fix up file perms for the power test extension so that chrome
    192         # can access it
    193         os.system('chmod -R 755 %s' % self.bindir)
    194 
    195         # setup a HTTP Server to listen for status updates from the power
    196         # test extension
    197         self._testServer = httpd.HTTPListener(8001, docroot=self.bindir)
    198         self._testServer.run()
    199 
    200         # initialize various interesting power related stats
    201         self._statomatic = power_status.StatoMatic()
    202 
    203         self._power_status.refresh()
    204         help_output = utils.system_output('check_powerd_config --help')
    205         if 'low_battery_shutdown' in help_output:
    206           logging.info('Have low_battery_shutdown option')
    207           self._sys_low_batt_p = float(utils.system_output(
    208                   'check_powerd_config --low_battery_shutdown_percent'))
    209           self._sys_low_batt_s = int(utils.system_output(
    210                   'check_powerd_config --low_battery_shutdown_time'))
    211         else:
    212           # TODO(dchan) Once M57 in stable, remove this option and function.
    213           logging.info('No low_battery_shutdown option')
    214           (self._sys_low_batt_p, self._sys_low_batt_s) = \
    215               self._get_sys_low_batt_values_from_log()
    216 
    217         if self._sys_low_batt_p and self._sys_low_batt_s:
    218             raise error.TestError(
    219                     "Low battery percent and seconds are non-zero.")
    220 
    221         min_low_batt_p = min(self._sys_low_batt_p + low_batt_margin_p, 100)
    222         if self._sys_low_batt_p and (min_low_batt_p > self._test_low_batt_p):
    223             logging.warning("test low battery threshold is below system " +
    224                          "low battery requirement.  Setting to %f",
    225                          min_low_batt_p)
    226             self._test_low_batt_p = min_low_batt_p
    227 
    228         if self._power_status.battery:
    229             self._ah_charge_start = self._power_status.battery[0].charge_now
    230             self._wh_energy_start = self._power_status.battery[0].energy
    231 
    232 
    233     def run_once(self):
    234         """Test main loop."""
    235         t0 = time.time()
    236 
    237         # record the PSR related info.
    238         psr = power_utils.DisplayPanelSelfRefresh(init_time=t0)
    239 
    240         try:
    241             self._keyboard_backlight = power_utils.KbdBacklight()
    242             self._set_keyboard_backlight_level()
    243         except power_utils.KbdBacklightException as e:
    244             logging.info("Assuming no keyboard backlight due to :: %s", str(e))
    245             self._keyboard_backlight = None
    246 
    247         measurements = []
    248         if self._power_status.battery:
    249             measurements += \
    250                     [power_status.SystemPower(self._power_status.battery_path)]
    251         if power_utils.has_powercap_support():
    252             measurements += power_rapl.create_powercap()
    253         elif power_utils.has_rapl_support():
    254             measurements += power_rapl.create_rapl()
    255         self._plog = power_status.PowerLogger(measurements, seconds_period=20)
    256         self._tlog = power_status.TempLogger([], seconds_period=20)
    257         self._plog.start()
    258         self._tlog.start()
    259         if self._log_mem_bandwidth:
    260             self._mlog = memory_bandwidth_logger.MemoryBandwidthLogger(
    261                 raw=False, seconds_period=2)
    262             self._mlog.start()
    263 
    264         ext_path = os.path.join(os.path.dirname(__file__), 'extension')
    265         self._tmp_keyvals['username'] = self._username
    266 
    267         arc_mode = arc_common.ARC_MODE_DISABLED
    268         if utils.is_arc_available():
    269             arc_mode = arc_common.ARC_MODE_ENABLED
    270 
    271         try:
    272             self._browser = chrome.Chrome(extension_paths=[ext_path],
    273                                           gaia_login=self._gaia_login,
    274                                           username=self._username,
    275                                           password=self._password,
    276                                           arc_mode=arc_mode)
    277         except exceptions.LoginException:
    278             # already failed guest login
    279             if not self._gaia_login:
    280                 raise
    281             self._gaia_login = False
    282             logging.warn("Unable to use GAIA acct %s.  Using GUEST instead.\n",
    283                          self._username)
    284             self._browser = chrome.Chrome(extension_paths=[ext_path],
    285                                           gaia_login=self._gaia_login)
    286         if not self._gaia_login:
    287             self._tmp_keyvals['username'] = 'GUEST'
    288 
    289         extension = self._browser.get_extension(ext_path)
    290         for k in params_dict:
    291             if getattr(self, params_dict[k]) is not '':
    292                 extension.ExecuteJavaScript('var %s = %s;' %
    293                                             (k, getattr(self, params_dict[k])))
    294 
    295         # This opens a trap start page to capture tabs opened for first login.
    296         # It will be closed when startTest is run.
    297         extension.ExecuteJavaScript('chrome.windows.create(null, null);')
    298 
    299         for i in range(self._loop_count):
    300             start_time = time.time()
    301             extension.ExecuteJavaScript('startTest();')
    302             # the power test extension will report its status here
    303             latch = self._testServer.add_wait_url('/status')
    304 
    305             # this starts a thread in the server that listens to log
    306             # information from the script
    307             script_logging = self._testServer.add_wait_url(url='/log')
    308 
    309             # dump any log entry that comes from the script into
    310             # the debug log
    311             self._testServer.add_url_handler(url='/log',\
    312                 handler_func=(lambda handler, forms, loop_counter=i:\
    313                     _extension_log_handler(handler, forms, loop_counter)))
    314 
    315             pagelt_tracking = self._testServer.add_wait_url(url='/pagelt')
    316 
    317             self._testServer.add_url_handler(url='/pagelt',\
    318                 handler_func=(lambda handler, forms, tracker=self, loop_counter=i:\
    319                     _extension_page_load_info_handler(handler, forms, loop_counter, self)))
    320 
    321             # reset backlight level since powerd might've modified it
    322             # based on ambient light
    323             self._set_backlight_level()
    324             self._set_lightbar_level()
    325             if self._keyboard_backlight:
    326                 self._set_keyboard_backlight_level()
    327             audio_helper.set_volume_levels(self._volume_level,
    328                                            self._mic_gain)
    329 
    330             low_battery = self._do_wait(self._verbose, self._loop_time,
    331                                         latch)
    332 
    333             script_logging.set();
    334             pagelt_tracking.set();
    335             self._plog.checkpoint('loop%d' % (i), start_time)
    336             self._tlog.checkpoint('loop%d' % (i), start_time)
    337             if self._verbose:
    338                 logging.debug('loop %d completed', i)
    339 
    340             if low_battery:
    341                 logging.info('Exiting due to low battery')
    342                 break
    343 
    344         # done with logging from the script, so we can collect that thread
    345         t1 = time.time()
    346         psr.refresh()
    347         self._tmp_keyvals['minutes_battery_life_tested'] = (t1 - t0) / 60
    348         self._tmp_keyvals.update(psr.get_keyvals())
    349 
    350 
    351     def postprocess_iteration(self):
    352         """Postprocess: write keyvals / log and send data to power dashboard."""
    353         def _log_stats(prefix, stats):
    354             if not len(stats):
    355                 return
    356             np = numpy.array(stats)
    357             logging.debug("%s samples: %d", prefix, len(np))
    358             logging.debug("%s mean:    %.2f", prefix, np.mean())
    359             logging.debug("%s stdev:   %.2f", prefix, np.std())
    360             logging.debug("%s max:     %.2f", prefix, np.max())
    361             logging.debug("%s min:     %.2f", prefix, np.min())
    362 
    363 
    364         def _log_per_loop_stats():
    365             samples_per_loop = self._loop_time / self._wait_time + 1
    366             for kname in self._stats:
    367                 start_idx = 0
    368                 loop = 1
    369                 for end_idx in xrange(samples_per_loop, len(self._stats[kname]),
    370                                       samples_per_loop):
    371                     _log_stats("%s loop %d" % (kname, loop),
    372                                self._stats[kname][start_idx:end_idx])
    373                     loop += 1
    374                     start_idx = end_idx
    375 
    376 
    377         def _log_all_stats():
    378             for kname in self._stats:
    379                 _log_stats(kname, self._stats[kname])
    380 
    381 
    382         keyvals = self._plog.calc()
    383         keyvals.update(self._tlog.calc())
    384         keyvals.update(self._statomatic.publish())
    385 
    386         if self._log_mem_bandwidth:
    387             self._mlog.stop()
    388             self._mlog.join()
    389 
    390         _log_all_stats()
    391         _log_per_loop_stats()
    392 
    393         # record battery stats
    394         if self._power_status.battery:
    395             keyvals['a_current_now'] = self._power_status.battery[0].current_now
    396             keyvals['ah_charge_full'] = \
    397                     self._power_status.battery[0].charge_full
    398             keyvals['ah_charge_full_design'] = \
    399                     self._power_status.battery[0].charge_full_design
    400             keyvals['ah_charge_start'] = self._ah_charge_start
    401             keyvals['ah_charge_now'] = self._power_status.battery[0].charge_now
    402             keyvals['ah_charge_used'] = keyvals['ah_charge_start'] - \
    403                                         keyvals['ah_charge_now']
    404             keyvals['wh_energy_start'] = self._wh_energy_start
    405             keyvals['wh_energy_now'] = self._power_status.battery[0].energy
    406             keyvals['wh_energy_used'] = keyvals['wh_energy_start'] - \
    407                                         keyvals['wh_energy_now']
    408             keyvals['v_voltage_min_design'] = \
    409                     self._power_status.battery[0].voltage_min_design
    410             keyvals['wh_energy_full_design'] = \
    411                     self._power_status.battery[0].energy_full_design
    412             keyvals['v_voltage_now'] = self._power_status.battery[0].voltage_now
    413 
    414         keyvals.update(self._tmp_keyvals)
    415 
    416         keyvals['percent_sys_low_battery'] = self._sys_low_batt_p
    417         keyvals['seconds_sys_low_battery'] = self._sys_low_batt_s
    418         voltage_np = numpy.array(self._stats['v_voltage_now'])
    419         voltage_mean = voltage_np.mean()
    420         keyvals['v_voltage_mean'] = voltage_mean
    421 
    422         keyvals['wh_energy_powerlogger'] = \
    423                              self._energy_use_from_powerlogger(keyvals)
    424 
    425         if not self._power_status.on_ac() and keyvals['ah_charge_used'] > 0:
    426             # For full runs, we should use charge to scale for battery life,
    427             # since the voltage swing is accounted for.
    428             # For short runs, energy will be a better estimate.
    429             if self._loop_count > 1:
    430                 estimated_reps = (keyvals['ah_charge_full_design'] /
    431                                   keyvals['ah_charge_used'])
    432             else:
    433                 estimated_reps = (keyvals['wh_energy_full_design'] /
    434                                   keyvals['wh_energy_powerlogger'])
    435 
    436             bat_life_scale =  estimated_reps * \
    437                               ((100 - keyvals['percent_sys_low_battery']) / 100)
    438 
    439             keyvals['minutes_battery_life'] = bat_life_scale * \
    440                 keyvals['minutes_battery_life_tested']
    441             # In the case where sys_low_batt_s is non-zero subtract those
    442             # minutes from the final extrapolation.
    443             if self._sys_low_batt_s:
    444                 keyvals['minutes_battery_life'] -= self._sys_low_batt_s / 60
    445 
    446             keyvals['a_current_rate'] = keyvals['ah_charge_used'] * 60 / \
    447                                         keyvals['minutes_battery_life_tested']
    448             keyvals['w_energy_rate'] = keyvals['wh_energy_used'] * 60 / \
    449                                        keyvals['minutes_battery_life_tested']
    450             if self._gaia_login:
    451                 self.output_perf_value(description='minutes_battery_life',
    452                                        value=keyvals['minutes_battery_life'],
    453                                        units='minutes',
    454                                        higher_is_better=True)
    455 
    456         if not self._gaia_login:
    457             keyvals = dict(map(lambda (key, value):
    458                                ('INVALID_' + str(key), value), keyvals.items()))
    459         else:
    460             for key, value in keyvals.iteritems():
    461                 if key.startswith('percent_cpuidle') and \
    462                    key.endswith('C0_time'):
    463                     self.output_perf_value(description=key,
    464                                            value=value,
    465                                            units='percent',
    466                                            higher_is_better=False)
    467 
    468         self.write_perf_keyval(keyvals)
    469         self._plog.save_results(self.resultsdir)
    470         self._tlog.save_results(self.resultsdir)
    471         pdash = power_dashboard.PowerLoggerDashboard( \
    472                 self._plog, self.tagged_testname, self.resultsdir)
    473         pdash.upload()
    474 
    475 
    476     def cleanup(self):
    477         if self._backlight:
    478             self._backlight.restore()
    479         if self._services:
    480             self._services.restore_services()
    481 
    482         # cleanup backchannel interface
    483         # Prevent wifi congestion in test lab by forcing machines to forget the
    484         # wifi AP we connected to at the start of the test.
    485         if self._shill_proxy:
    486             self._shill_proxy.remove_all_wifi_entries()
    487         if self._backchannel:
    488             self._backchannel.teardown()
    489         if self._browser:
    490             self._browser.close()
    491         if self._testServer:
    492             self._testServer.stop()
    493 
    494 
    495     def _do_wait(self, verbose, seconds, latch):
    496         latched = False
    497         low_battery = False
    498         total_time = seconds + self._wait_time
    499         elapsed_time = 0
    500 
    501         while elapsed_time < total_time:
    502             time.sleep(self._wait_time)
    503             elapsed_time += self._wait_time
    504 
    505             self._power_status.refresh()
    506 
    507             if not self._ac_ok and self._power_status.on_ac():
    508                 raise error.TestError('Running on AC power now.')
    509 
    510             if self._power_status.battery:
    511                 charge_now = self._power_status.battery[0].charge_now
    512                 energy_rate = self._power_status.battery[0].energy_rate
    513                 voltage_now = self._power_status.battery[0].voltage_now
    514                 self._stats['w_energy_rate'].append(energy_rate)
    515                 self._stats['v_voltage_now'].append(voltage_now)
    516                 if verbose:
    517                     logging.debug('ah_charge_now %f', charge_now)
    518                     logging.debug('w_energy_rate %f', energy_rate)
    519                     logging.debug('v_voltage_now %f', voltage_now)
    520 
    521                 low_battery = (self._power_status.percent_current_charge() <
    522                                self._test_low_batt_p)
    523 
    524             latched = latch.is_set()
    525 
    526             if latched or low_battery:
    527                 break
    528 
    529         if latched:
    530             # record chrome power extension stats
    531             form_data = self._testServer.get_form_entries()
    532             logging.debug(form_data)
    533             for e in form_data:
    534                 key = 'ext_' + e
    535                 if key in self._tmp_keyvals:
    536                     self._tmp_keyvals[key] += "_%s" % form_data[e]
    537                 else:
    538                     self._tmp_keyvals[key] = form_data[e]
    539         else:
    540             logging.debug("Didn't get status back from power extension")
    541 
    542         return low_battery
    543 
    544 
    545     def _set_backlight_level(self):
    546         self._backlight.set_default()
    547         # record brightness level
    548         self._tmp_keyvals['level_backlight_current'] = \
    549             self._backlight.get_level()
    550 
    551 
    552     def _set_lightbar_level(self, level='off'):
    553         """Set lightbar level.
    554 
    555         Args:
    556           level: string value to set lightbar to.  See ectool for more details.
    557         """
    558         rv = utils.system('which ectool', ignore_status=True)
    559         if rv:
    560             return
    561         rv = utils.system('ectool lightbar %s' % level, ignore_status=True)
    562         if rv:
    563             logging.info('Assuming no lightbar due to non-zero exit status')
    564         else:
    565             logging.info('Setting lightbar to %s', level)
    566             self._tmp_keyvals['level_lightbar_current'] = level
    567 
    568 
    569     def _get_sys_low_batt_values_from_log(self):
    570         """Determine the low battery values for device and return.
    571 
    572         2012/11/01: power manager (powerd.cc) parses parameters in filesystem
    573           and outputs a log message like:
    574 
    575            [1101/173837:INFO:powerd.cc(258)] Using low battery time threshold
    576                      of 0 secs and using low battery percent threshold of 3.5
    577 
    578            It currently checks to make sure that only one of these values is
    579            defined.
    580 
    581         Returns:
    582           Tuple of (percent, seconds)
    583             percent: float of low battery percentage
    584             seconds: float of low battery seconds
    585 
    586         """
    587         split_re = 'threshold of'
    588 
    589         powerd_log = '/var/log/power_manager/powerd.LATEST'
    590         cmd = 'grep "low battery time" %s' % powerd_log
    591         line = utils.system_output(cmd)
    592         secs = float(line.split(split_re)[1].split()[0])
    593         percent = float(line.split(split_re)[2].split()[0])
    594         return (percent, secs)
    595 
    596 
    597     def _has_light_sensor(self):
    598         """
    599         Determine if there is a light sensor on the board.
    600 
    601         @returns True if this host has a light sensor or
    602                  False if it does not.
    603         """
    604         # If the command exits with a failure status,
    605         # we do not have a light sensor
    606         cmd = 'check_powerd_config --ambient_light_sensor'
    607         result = utils.run(cmd, ignore_status=True)
    608         if result.exit_status:
    609             logging.debug('Ambient light sensor not present')
    610             return False
    611         logging.debug('Ambient light sensor present')
    612         return True
    613 
    614 
    615     def _energy_use_from_powerlogger(self, keyval):
    616         """
    617         Calculates the energy use, in Wh, used over the course of the run as
    618         reported by the PowerLogger.
    619 
    620         Args:
    621           keyval: the dictionary of keyvals containing PowerLogger output
    622 
    623         Returns:
    624           energy_wh: total energy used over the course of this run
    625 
    626         """
    627         energy_wh = 0
    628         loop = 0
    629         while True:
    630             duration_key = 'loop%d_system_duration' % loop
    631             avg_power_key = 'loop%d_system_pwr_avg' % loop
    632             if duration_key not in keyval or avg_power_key not in keyval:
    633                 break
    634             energy_wh += keyval[duration_key] * keyval[avg_power_key] / 3600
    635             loop += 1
    636         return energy_wh
    637 
    638 
    639     def _has_hover_detection(self):
    640         """
    641         Checks if hover is detected by the device.
    642 
    643         Returns:
    644             Returns True if the hover detection support is enabled.
    645             Else returns false.
    646         """
    647 
    648         cmd = 'check_powerd_config --hover_detection'
    649         result = utils.run(cmd, ignore_status=True)
    650         if result.exit_status:
    651             logging.debug('Hover not present')
    652             return False
    653         logging.debug('Hover present')
    654         return True
    655 
    656 
    657     def _set_keyboard_backlight_level(self):
    658         """
    659         Sets keyboard backlight based on light sensor and hover.
    660         These values are based on UMA as mentioned in
    661         https://bugs.chromium.org/p/chromium/issues/detail?id=603233#c10
    662 
    663         ALS  | hover | keyboard backlight level
    664         ---------------------------------------
    665         No   | No    | default
    666         ---------------------------------------
    667         Yes  | No    | 40% of default
    668         --------------------------------------
    669         No   | Yes   | System with this configuration does not exist
    670         --------------------------------------
    671         Yes  | Yes   | 30% of default
    672         --------------------------------------
    673 
    674         Here default is no Ambient Light Sensor, no hover,
    675         default always-on brightness level.
    676         """
    677 
    678         default_level = self._keyboard_backlight.get_default_level()
    679         level_to_set = default_level
    680         has_light_sensor = self._has_light_sensor()
    681         has_hover = self._has_hover_detection()
    682         # TODO(ravisadineni):if (crbug: 603233) becomes default
    683         # change this to reflect it.
    684         if has_light_sensor and has_hover:
    685             level_to_set = (30 * default_level) / 100
    686         elif has_light_sensor:
    687             level_to_set = (40 * default_level) / 100
    688         elif has_hover:
    689             logging.warn('Device has hover but no light sensor')
    690 
    691         logging.info('Setting keyboard backlight to %d', level_to_set)
    692         self._keyboard_backlight.set_level(level_to_set)
    693         self._tmp_keyvals['percent_kbd_backlight'] = \
    694             self._keyboard_backlight.get_percent()
    695 
    696 def _extension_log_handler(handler, form, loop_number):
    697     """
    698     We use the httpd library to allow us to log whatever we
    699     want from the extension JS script into the log files.
    700 
    701     This method is provided to the server as a handler for
    702     all requests that come for the log url in the testServer
    703 
    704     unused parameter, because httpd passes the server itself
    705     into the handler.
    706     """
    707     if form:
    708         for field in form.keys():
    709             logging.debug("[extension] @ loop_%d %s", loop_number,
    710             form[field].value)
    711             # we don't want to add url information to our keyvals.
    712             # httpd adds them automatically so we remove them again
    713             del handler.server._form_entries[field]
    714 
    715 def _extension_page_load_info_handler(handler, form, loop_number, tracker):
    716     stats_ids = ['mean', 'min', 'max', 'std']
    717     time_measurements = []
    718     sorted_pagelt = []
    719     #show up to this number of slow page-loads
    720     num_slow_page_loads = 5;
    721 
    722     if not form:
    723         logging.debug("no page load information returned")
    724         return;
    725 
    726     for field in form.keys():
    727         url = field[str.find(field, "http"):]
    728         load_time = int(form[field].value)
    729 
    730         time_measurements.append(load_time)
    731         sorted_pagelt.append((url, load_time))
    732 
    733         logging.debug("[extension] @ loop_%d url: %s load time: %d ms",
    734             loop_number, url, load_time)
    735         # we don't want to add url information to our keyvals.
    736         # httpd adds them automatically so we remove them again
    737         del handler.server._form_entries[field]
    738 
    739     time_measurements = numpy.array(time_measurements)
    740     stats_vals = [time_measurements.mean(), time_measurements.min(),
    741     time_measurements.max(),time_measurements.std()]
    742 
    743     key_base = 'ext_ms_page_load_time_'
    744     for i in range(len(stats_ids)):
    745         key = key_base + stats_ids[i]
    746         if key in tracker._tmp_keyvals:
    747             tracker._tmp_keyvals[key] += "_%.2f" % stats_vals[i]
    748         else:
    749             tracker._tmp_keyvals[key] = "%.2f" % stats_vals[i]
    750 
    751 
    752     sorted_pagelt.sort(key=lambda item: item[1], reverse=True)
    753 
    754     message = "The %d slowest page-load-times are:\n" % (num_slow_page_loads)
    755     for url, msecs in sorted_pagelt[:num_slow_page_loads]:
    756         message += "\t%s w/ %d ms" % (url, msecs)
    757 
    758     logging.debug("%s\n", message)
    759