1# Copyright 2019 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"""Wrap test suite with power_ServodWrapper and run in a time-limited loop.""" 6 7import logging 8import random 9import time 10 11from autotest_lib.client.common_lib import error 12from autotest_lib.client.common_lib.cros import retry 13from autotest_lib.server import test 14from autotest_lib.server.cros.dynamic_suite import suite 15from autotest_lib.server.cros.power import servo_charger 16 17# Timeout in seconds to attempt to ping the DUT. 18DUT_PINGABLE_TIMEOUT_S = 30.0 19# Delay in seconds before reattempting to ping the DUT. 20VERIFY_DUT_PINGABLE_DELAY_S = 10.0 21# Number of times to attempt to ping (and reset on failure) the DUT. 22VERIFY_DUT_PINGABLE_TRIES = 3 23# Timeout in minutes to supply to retry decorator for dut pingable verifiction. 24VERIFY_DUT_PINGABLE_TIMEOUT_MIN = ((DUT_PINGABLE_TIMEOUT_S + 25 VERIFY_DUT_PINGABLE_DELAY_S) / 60.0 * 26 (VERIFY_DUT_PINGABLE_TRIES + 1)) 27# Delay in seconds before reattempting to query DUT EC for battery charge after 28# reset. 29GET_CHARGE_WITH_RESET_DELAY_S = 3.0 30# Number of times to attempt to get the battery charge (and reset on failure) 31# the DUT. 32GET_CHARGE_WITH_RESET_TRIES = 3 33# Timeout in minutes to supply to retry decorator to get charge with hard reset. 34GET_CHARGE_WITH_RESET_TIMEOUT_MIN = (GET_CHARGE_WITH_RESET_DELAY_S / 60.0 * 35 (GET_CHARGE_WITH_RESET_TRIES + 1)) 36# Delay in seconds before reattempting to query DUT EC for battery charge after 37# timeout/error from EC console 38GET_CHARGE_DELAY_S = 0.1 39# Number of times to attempt to get the battery charge from the DUT. 40GET_CHARGE_TRIES = 3 41# Timeout in minutes to supply to retry decorator to get charge. 42GET_CHARGE_TIMEOUT_MIN = (GET_CHARGE_DELAY_S / 60.0 * 43 (GET_CHARGE_TRIES + 1)) 44# Delay in seconds before attempting to query EC again after reset. 45EC_RESET_DELAY_S = 3.0 46# Delay in seconds to allow the system to detect AP shutdown. 47AP_SHUTDOWN_DELAY_S = 10.0 48# Polling rate in seconds to poll battery charge to determine charging complete. 49CHARGE_STATE_POLLING_RATE_S = 60.0 50 51class power_Monitoring(test.test): 52 """Time limited loop for running power suites with power_ServodWrapper. 53 54 This test runs a given suite of client tests with power_ServodWrapper 55 for a given amount of time, ensuring that if the battery level drops 56 below a configurable percentage it will be charged back up to a configurable 57 percentage. 58 """ 59 version = 1 60 61 # The 'real' server side test to use to wrap power tests. 62 WRAPPER_TEST = 'power_ServodWrapper' 63 # The default suite of tests to run with monitoring. 64 DEFAULT_SUITE = 'power_monitoring' 65 # The default runtime in hours for the suite. 66 DEFAULT_RUNTIME_HR = 12.0 67 # The maximum runtime for monitoring. 6 weeks. 68 # Longer command line configurations will be ignored. 69 MAX_RUNTIME_HR = 6 * 7 * 24.0 70 # The minimum runtime for monitoring. 71 # Lower command line configurations will be ignored. 72 MIN_RUNTIME_HR = 0.1 73 # The default battery charge percent to stop charging the DUT. 74 DEFAULT_STOP_CHARGING_LEVEL = 75.0 75 # The default battery charge percent to start charging the DUT. 76 DEFAULT_START_CHARGING_LEVEL = 25.0 77 # The maximum battery charge percent to stop charging the DUT. 78 # Higher command line configurations will be ignored. 79 MAX_STOP_CHARGING_LEVEL = 95.0 80 # The minimum battery charge percent to start charging the DUT. 81 # Lower command line configurations will be ignored. 82 MIN_START_CHARGING_LEVEL = 4.0 83 # Maximum number of consecutive failures allowed before the monitoring 84 # is aborted. 85 MAX_CONSECUTIVE_FAILURES = 5 86 # Max time to charge from 0 to 100%. Plenty of room for slow charging. 87 MAX_CHARGING_TIME_HR = 5 88 89 def initialize(self, host, config={}): 90 """Setup power monitoring. 91 92 @param host: CrosHost object representing the DUT. 93 @param config: the args argument from test_that in a dict. 94 -start_charging_level: float, battery level when charging triggers 95 -stop_charging_level: float, battery level when charging stops 96 -suite: suite to loop over 97 -runtime_hr: runtime in hours the monitoring should run 98 -pdash_note: note to add to power dashboard upload 99 """ 100 # power_Monitoring is a wrapper around a wrapper - it does not need 101 # to collect all the sysinfo information and potentially be stuck 102 # there waiting for a dead device to resurface. 103 self.job.fast = True 104 start = float(config.get('start_charging_level', 105 self.DEFAULT_START_CHARGING_LEVEL)) 106 stop = float(config.get('stop_charging_level', 107 self.DEFAULT_STOP_CHARGING_LEVEL)) 108 self.stop_charging_level = min(stop, self.MAX_STOP_CHARGING_LEVEL) 109 self.start_charging_level = max(start, self.MIN_START_CHARGING_LEVEL) 110 self._host = host 111 servo = host.servo 112 self._charger = servo_charger.ServoV4ChargeManager(host, servo) 113 self._charger.stop_charging(verify=True) 114 115 # If no suite is defined, run with power_monitoring suite. 116 test_suite = config.get('suite', self.DEFAULT_SUITE) 117 runtime_hr = float(config.get('runtime_hr', self.DEFAULT_RUNTIME_HR)) 118 self._runtime_hr = min(max(runtime_hr, self.MIN_RUNTIME_HR), 119 self.MAX_RUNTIME_HR) 120 121 fs_getter = suite.create_fs_getter(self.autodir) 122 # Find the wrapper test. 123 w_predicate = suite.test_name_equals_predicate(self.WRAPPER_TEST) 124 self._wrapper_test = suite.find_and_parse_tests(fs_getter, w_predicate) 125 if not self._wrapper_test: 126 raise error.TestFail('%r wrapper test not found.' % 127 self.WRAPPER_TEST) 128 # Find the test suite in autotest file system. 129 predicate = suite.name_in_tag_predicate(test_suite) 130 self._tests = suite.find_and_parse_tests(fs_getter, predicate) 131 if not self._tests: 132 raise error.TestNAError('%r suite has no tests under it.' % 133 test_suite) 134 # Sort the tests by their name. 135 self._tests.sort(key=lambda t: t.name) 136 self._pdash_note = config.get('pdash_note', '') 137 138 def run_once(self, host): 139 """Measure power while running the client side tests in a loop. 140 141 @param host: CrosHost object representing the DUT. 142 """ 143 # Figure out end timestamp. 144 end = time.time() + self._runtime_hr * 60 * 60 145 logging.info('Will be looping over the tests: %s. Order will be ' 146 'randomized.', ', '.join(t.name for t in self._tests)) 147 random.shuffle(self._tests) 148 wrapper_name = self._wrapper_test[0].name 149 logging.debug('Going to run the tests on wrapper %s.', wrapper_name) 150 # Keep track of consecutive failures to bail out if it seems that 151 # tests are not passing. 152 consecutive_failures = test_run = 0 153 while time.time() < end: 154 # First verify and charge DUT to configured percentage. 155 self._verify_and_charge_dut() 156 # Use tests as a queue where the first test is always run 157 # and inserted in the back again at the end. 158 current_test = self._tests.pop(0) 159 logging.info('About to run monitoring on %s.', current_test.name) 160 wrapper_config = {'test': current_test.name} 161 subdir_tag = '%05d' % test_run 162 if self._pdash_note: 163 wrapper_config['pdash_note'] = self._pdash_note 164 try: 165 self.job.run_test(wrapper_name, host=host, 166 config=wrapper_config, subdir_tag=subdir_tag) 167 consecutive_failures = 0 168 except Exception as e: 169 # Broad except as we don't really care about the exception 170 # but rather want to make sure that we know how many failures 171 # have happened in a row. 172 logging.warn('Issue running %s: %s', current_test.name, str(e)) 173 consecutive_failures += 1 174 if consecutive_failures >= self.MAX_CONSECUTIVE_FAILURES: 175 raise error.TestFail('%d consecutive failures. Stopping.' % 176 consecutive_failures) 177 test_run += 1 178 # Add the test back to the pipe. 179 self._tests.append(current_test) 180 181 def cleanup(self): 182 """Turn on charging at the end again.""" 183 self._charger.start_charging(verify=False) 184 185 @retry.retry(error.TestFail, timeout_min=GET_CHARGE_TIMEOUT_MIN, 186 delay_sec=GET_CHARGE_DELAY_S) 187 def _get_charge_percent(self): 188 """Retrieve battery_charge_percent from the DUT in a retry loop.""" 189 return float(self._host.servo.get('battery_charge_percent')) 190 191 @retry.retry(error.TestFail, timeout_min=GET_CHARGE_WITH_RESET_TIMEOUT_MIN, 192 delay_sec=GET_CHARGE_WITH_RESET_DELAY_S) 193 def _force_get_charge_percent(self): 194 """Attempt to get the charge percent through cold reset if necessary.""" 195 try: 196 return self._get_charge_percent() 197 except error.TestFail as e: 198 logging.warn('Failed to get battery charge levels even ', 199 'after turning on charging. Cold resetting.' 200 'before re-attempting.') 201 self._host.servo._power_state.reset() 202 # Allow DUT time after cold reset to come back. 203 time.sleep(EC_RESET_DELAY_S) 204 raise error.TestFail('Failed to get battery charge percent. %s', 205 str(e)) 206 207 def _charge_dut(self): 208 """Charge the DUT up.""" 209 self._charger.start_charging() 210 time.sleep(EC_RESET_DELAY_S) 211 current_charge = start_charge = self._force_get_charge_percent() 212 logging.debug('Charge level of %d%%. Going to charge up.', 213 current_charge) 214 charge_time_mltp = max(self.stop_charging_level - 215 current_charge, 0.0)/100 216 # Calculate how many seconds to allow at most for charging. 217 charge_time = charge_time_mltp * self.MAX_CHARGING_TIME_HR * 60 * 60 218 logging.debug('Going to charge for at most %d minutes.', 219 charge_time/60) 220 start = time.time() 221 end = start + charge_time 222 # Shut down the AP to increase charging speed. 223 self._host.servo.set_nocheck('ec_uart_cmd', 'apshutdown') 224 # Give the EC time to shutdown properly. 225 time.sleep(AP_SHUTDOWN_DELAY_S) 226 while time.time() < end and (current_charge < 227 self.stop_charging_level): 228 logging.debug('Charge level at %d%%. Continuing to charge ' 229 'until %d%%.', current_charge, 230 self.stop_charging_level) 231 # Poll once a minute. 232 time.sleep(CHARGE_STATE_POLLING_RATE_S) 233 current_charge = self._get_charge_percent() 234 if current_charge < self.stop_charging_level: 235 # Restart the AP again before indicating failure. 236 self._host.servo.set_nocheck('ec_uart_cmd', 'powerbtn') 237 raise error.TestFail('Dut only charged from %d%% to %d%% in %d ' 238 'minutes.' % (start_charge, current_charge, 239 int((time.time()-start)/60))) 240 else: 241 logging.debug('Charging finished. Charge at %d%% after %d ' 242 'minutes.', current_charge, (time.time() - start)) 243 self._charger.stop_charging(verify=True) 244 # AP was shutdown. Restart it again. 245 self._host.servo.set_nocheck('ec_uart_cmd', 'powerbtn') 246 247 @retry.retry(error.TestFail, timeout_min=VERIFY_DUT_PINGABLE_TIMEOUT_MIN, 248 delay_sec=VERIFY_DUT_PINGABLE_DELAY_S) 249 def _verify_dut(self): 250 """Verify DUT can be pinged. Reset if DUT not responsive.""" 251 if not self._host.ping_wait_up(timeout=DUT_PINGABLE_TIMEOUT_S): 252 self._host.servo._power_state.reset() 253 raise error.TestFail('Dut did not reboot or respond to ping after ' 254 'charging.') 255 256 def _verify_and_charge_dut(self): 257 """Charge DUT up to |stop_charging| level if below |start_charging|.""" 258 try: 259 if self._get_charge_percent() < self.start_charging_level: 260 # Only go through the charging sequence if necessary. 261 self._charge_dut() 262 except error.TestFail: 263 # Failure to initially get the charge might be due to the EC being 264 # off. Try charging to see whether that recovers the device. 265 self._charge_dut() 266 self._verify_dut() 267