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