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