1# Copyright 2017 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 logging 6import pprint 7import time 8 9from autotest_lib.client.common_lib import error 10from autotest_lib.server import autotest 11from autotest_lib.server.cros.faft.firmware_test import FirmwareTest 12 13 14class firmware_Cr50DeviceState(FirmwareTest): 15 """Verify Cr50 tracks the EC and AP state correctly. 16 17 Put the device through S0, S0ix, S3, and G3. Cr50 responds to these state 18 changes by enabling/disabling uart and changing its suspend type. Verify 19 that none of these cause any interrupt storms on Cr50. Make sure that there 20 aren't any interrupt storms and that Cr50 enters regular or deep sleep a 21 reasonable amount of times. 22 """ 23 version = 1 24 25 DEEP_SLEEP_STEP_SUFFIX = ' Num Deep Sleep Steps' 26 27 # Use negative numbers to keep track of counts not in the IRQ list. 28 KEY_DEEP_SLEEP = -3 29 KEY_TIME = -2 30 KEY_RESET = -1 31 KEY_REGULAR_SLEEP = 112 32 INT_NAME = { 33 KEY_RESET : 'Reset Count', 34 KEY_DEEP_SLEEP : 'Deep Sleep Count', 35 KEY_TIME : 'Cr50 Time', 36 4 : 'HOST_CMD_DONE', 37 81 : 'GPIO0', 38 98 : 'GPIO1', 39 103 : 'I2CS WRITE', 40 KEY_REGULAR_SLEEP : 'PMU WAKEUP', 41 113 : 'AC present FED', 42 114 : 'AC present RED', 43 124 : 'RBOX_INTR_PWRB', 44 130 : 'SPS CS deassert', 45 138 : 'SPS RXFIFO LVL', 46 159 : 'SPS RXFIFO overflow', 47 160 : 'EVENT TIMER', 48 174 : 'CR50_RX_SERVO_TX', 49 177 : 'CR50_TX_SERVO_RX', 50 181 : 'AP_TX_CR50_RX', 51 184 : 'AP_RX_CR50_TX', 52 188 : 'EC_TX_CR50_RX', 53 191 : 'EC_RX_CR50_TX', 54 193 : 'USB', 55 } 56 SLEEP_KEYS = [ KEY_REGULAR_SLEEP, KEY_DEEP_SLEEP ] 57 # Cr50 won't enable any form of sleep until it has been up for 20 seconds. 58 SLEEP_DELAY = 20 59 # The time in seconds to wait in each state 60 SLEEP_TIME = 30 61 SHORT_WAIT = 5 62 CONSERVATIVE_WAIT_TIME = SLEEP_TIME + SHORT_WAIT + 10 63 # Cr50 should wake up twice per second while in regular sleep 64 SLEEP_RATE = 2 65 66 DEEP_SLEEP_MAX = 2 67 ARM = 'ARM ' 68 69 # If there are over 100,000 interrupts, it is an interrupt storm. 70 DEFAULT_COUNTS = [0, 100000] 71 # A dictionary of ok count values for each irq that shouldn't follow the 72 # DEFAULT_COUNTS range. 73 EXPECTED_IRQ_COUNT_RANGE = { 74 KEY_RESET : [0, 0], 75 KEY_DEEP_SLEEP : [0, DEEP_SLEEP_MAX], 76 KEY_TIME : [0, CONSERVATIVE_WAIT_TIME], 77 'S0ix ' + DEEP_SLEEP_STEP_SUFFIX : [0, 0], 78 # Cr50 may enter deep sleep an extra time, because of how the test 79 # collects taskinfo counts. Just verify that it does enter deep sleep 80 'S3 ' + DEEP_SLEEP_STEP_SUFFIX : [1, 2], 81 'G3 ' + DEEP_SLEEP_STEP_SUFFIX : [1, 2], 82 # ARM devices don't enter deep sleep in S3 83 ARM + 'S3' + DEEP_SLEEP_STEP_SUFFIX : [0, 0], 84 ARM + 'G3' + DEEP_SLEEP_STEP_SUFFIX : [1, 2], 85 # Regular sleep is calculated based on the cr50 time 86 } 87 88 GET_TASKINFO = ['IRQ counts by type:(.*)Service calls'] 89 90 START = '' 91 INCREASE = '+' 92 DS_RESUME = 'DS' 93 94 def get_taskinfo_output(self): 95 """Return a dict with the irq numbers as keys and counts as values""" 96 output = self.cr50.send_command_get_output('taskinfo', 97 self.GET_TASKINFO)[0][1].strip() 98 return output 99 100 101 def get_irq_counts(self): 102 """Return a dict with the irq numbers as keys and counts as values""" 103 output = self.get_taskinfo_output() 104 irq_list = output.split('\n') 105 # Make sure the regular sleep irq is in the dictionary, even if cr50 106 # hasn't seen any interrupts. It's important the test sees that there's 107 # never an interrupt. 108 irq_counts = { self.KEY_REGULAR_SLEEP : 0 } 109 for irq_info in irq_list: 110 num, count = irq_info.split() 111 irq_counts[int(num)] = int(count) 112 irq_counts[self.KEY_RESET] = int(self.servo.get('cr50_reset_count')) 113 irq_counts[self.KEY_DEEP_SLEEP] = int(self.cr50.get_deep_sleep_count()) 114 irq_counts[self.KEY_TIME] = int(self.cr50.gettime()) 115 return irq_counts 116 117 118 def get_expected_count(self, irq_key, cr50_time): 119 """Get the expected irq increase for the given irq and state 120 121 Args: 122 irq_key: the irq int 123 cr50_time: the cr50 time in seconds 124 125 Returns: 126 A list with the expected irq count range [min, max] 127 """ 128 # CCD will prevent sleep 129 if self.ccd_enabled and (irq_key in self.SLEEP_KEYS or 130 self.DEEP_SLEEP_STEP_SUFFIX in str(irq_key)): 131 return [0, 0] 132 if irq_key == self.KEY_REGULAR_SLEEP: 133 min_count = max(cr50_time - self.SLEEP_DELAY, 0) 134 # Just checking there is not a lot of extra sleep wakeups. Add 1 to 135 # the sleep rate so cr50 can have some extra wakeups, but not too 136 # many. 137 max_count = cr50_time * (self.SLEEP_RATE + 1) 138 return [min_count, max_count] 139 return self.EXPECTED_IRQ_COUNT_RANGE.get(irq_key, self.DEFAULT_COUNTS) 140 141 142 def check_increase(self, irq_key, name, increase, expected_range): 143 """Verify the irq count is within the expected range 144 145 Args: 146 irq_key: the irq int 147 name: the irq name string 148 increase: the irq count 149 expected_range: A list with the valid irq count range [min, max] 150 151 Returns: 152 '' if increase is in the given range. If the increase isn't in the 153 range, it returns an error message. 154 """ 155 min_count, max_count = expected_range 156 if min_count > increase or max_count < increase: 157 err_msg = '%s %s: %s not in range %s' % (name, irq_key, increase, 158 expected_range) 159 return err_msg 160 return '' 161 162 163 def get_step_events(self): 164 """Use the deep sleep counts to determine the step events""" 165 ds_counts = self.get_irq_step_counts(self.KEY_DEEP_SLEEP) 166 events = [] 167 for i, count in enumerate(ds_counts): 168 if not i: 169 events.append(self.START) 170 elif count != ds_counts[i - 1]: 171 # If the deep sleep count changed, Cr50 recovered deep sleep 172 # and the irq counts are reset. 173 events.append(self.DS_RESUME) 174 else: 175 events.append(self.INCREASE) 176 return events 177 178 179 def get_irq_step_counts(self, irq_key): 180 """Get a list of the all of the step counts for the given irq""" 181 return [ irq_dict.get(irq_key, 0) for irq_dict in self.steps ] 182 183 184 def check_for_errors(self, state): 185 """Check for unexpected IRQ counts at each step. 186 187 Find the irq count errors and add them to run_errors. 188 189 Args: 190 state: The power state: S0, S0ix, S3, or G3. 191 """ 192 num_steps = len(self.steps) 193 # Get all of the deep sleep counts 194 events = self.get_step_events() 195 196 irq_list = list(self.irqs) 197 irq_list.sort() 198 199 irq_diff = ['%23s' % 'step' + ''.join(self.step_names)] 200 step_errors = [ [] for i in range(num_steps) ] 201 202 cr50_times = self.get_irq_step_counts(self.KEY_TIME) 203 cr50_diffs = [] 204 for i, cr50_time in enumerate(cr50_times): 205 if events[i] == self.INCREASE: 206 cr50_time -= cr50_times[i - 1] 207 cr50_diffs.append(cr50_time) 208 209 # Go through each irq and update its info in the progress dict 210 for irq_key in irq_list: 211 name = self.INT_NAME.get(irq_key, 'Unknown') 212 irq_progress_str = ['%19s %3s:' % (name, irq_key)] 213 214 irq_counts = self.get_irq_step_counts(irq_key) 215 for step, count in enumerate(irq_counts): 216 event = events[step] 217 218 # The deep sleep counts are not reset after deep sleep. Change 219 # the event to INCREASE. 220 if irq_key == self.KEY_DEEP_SLEEP and event == self.DS_RESUME: 221 event = self.INCREASE 222 223 if event == self.INCREASE: 224 count -= irq_counts[step - 1] 225 226 # Check that the count increase is within the expected value. 227 if event != self.START: 228 expected_range = self.get_expected_count(irq_key, 229 cr50_diffs[step]) 230 231 rv = self.check_increase(irq_key, name, count, 232 expected_range) 233 if rv: 234 logging.info('Unexpected count for %s %s', state, rv) 235 step_errors[step].append(rv) 236 237 irq_progress_str.append(' %2s %7d' % (event, count)) 238 239 irq_diff.append(''.join(irq_progress_str)) 240 241 errors = {} 242 243 ds_key = self.ARM if self.is_arm else '' 244 ds_key += state + self.DEEP_SLEEP_STEP_SUFFIX 245 expected_range = self.get_expected_count(ds_key, 0) 246 rv = self.check_increase(None, ds_key, events.count(self.DS_RESUME), 247 expected_range) 248 if rv: 249 logging.info('Unexpected count for %s %s', state, rv) 250 errors[ds_key] = rv 251 for i, step_error in enumerate(step_errors): 252 if step_error: 253 logging.error('Step %d errors:\n%s', i, 254 pprint.pformat(step_error)) 255 step = '%s step %d %s' % (state, i, self.step_names[i].strip()) 256 errors[step] = step_error 257 258 logging.info('DIFF %s IRQ Counts:\n%s', state, pprint.pformat(irq_diff)) 259 if errors: 260 logging.info('ERRORS %s IRQ Counts:\n%s', state, 261 pprint.pformat(errors)) 262 self.run_errors.update(errors) 263 264 265 def enter_state(self, state): 266 """Get the command to enter the power state""" 267 self.stage_irq_add(self.get_irq_counts(), 'start %s' % state) 268 if state == 'S0': 269 self.servo.power_short_press() 270 else: 271 if state == 'S0ix': 272 full_command = 'echo freeze > /sys/power/state &' 273 elif state == 'S3': 274 full_command = 'echo mem > /sys/power/state &' 275 elif state == 'G3': 276 full_command = 'poweroff' 277 self.faft_client.system.run_shell_command(full_command) 278 279 time.sleep(self.SHORT_WAIT); 280 # check S3 state transition 281 if not self.wait_power_state(state, self.SHORT_WAIT): 282 raise error.TestFail('Platform failed to reach %s state.' % state) 283 self.stage_irq_add(self.get_irq_counts(), 'in %s' % state) 284 285 286 def stage_irq_add(self, irq_dict, name=''): 287 """Add the current irq counts to the stored dictionary of irq info""" 288 self.steps.append(irq_dict) 289 self.step_names.append('%11s' % name) 290 self.irqs.update(irq_dict.keys()) 291 292 293 def reset_irq_counts(self): 294 """Reset the test IRQ counts""" 295 self.steps = [] 296 self.step_names = [] 297 self.irqs = set() 298 299 300 def run_transition(self, state): 301 """Verify there are no Cr50 interrupt storms in the power state. 302 303 Enter the power state, return to S0, and then verify that Cr50 behaved 304 correctly. 305 306 Args: 307 state: the power state: S0ix, S3, or G3 308 """ 309 self.reset_irq_counts() 310 311 # Enter the given state 312 self.enter_state(state) 313 314 logging.info('waiting %d seconds', self.SLEEP_TIME) 315 time.sleep(self.SLEEP_TIME) 316 317 # Return to S0 318 self.enter_state('S0') 319 320 # Check that the progress of the irq counts seems reasonable 321 self.check_for_errors(state) 322 323 324 def is_arm_family(self): 325 """Returns True if the DUT is an ARM device.""" 326 arch = self.host.run('arch').stdout.strip() 327 return arch in ['aarch64', 'armv7l'] 328 329 330 def run_through_power_states(self): 331 """Go through S0ix, S3, and G3. Verify there are no interrupt storms""" 332 self.run_errors = {} 333 self.ccd_str = 'ccd ' + ('enabled' if self.ccd_enabled else 'disabled') 334 logging.info('Running through states with %s', self.ccd_str) 335 336 # Initialize the Test IRQ counts 337 self.reset_irq_counts() 338 339 # Make sure the DUT is in s0 340 self.enter_state('S0') 341 342 # Login before entering S0ix so cr50 will be able to enter regular sleep 343 if not self.is_arm: 344 client_at = autotest.Autotest(self.host) 345 client_at.run_test('login_LoginSuccess') 346 self.run_transition('S0ix') 347 348 # Enter S3 349 self.run_transition('S3') 350 351 # Enter G3 352 self.run_transition('G3') 353 if self.run_errors: 354 self.all_errors[self.ccd_str] = self.run_errors 355 356 357 def run_once(self, host): 358 """Go through S0ix, S3, and G3. Verify there are no interrupt storms""" 359 self.all_errors = {} 360 self.host = host 361 self.is_arm = self.is_arm_family() 362 self.cr50.ccd_disable(raise_error=False) 363 self.ccd_enabled = self.cr50.ccd_is_enabled() 364 self.run_through_power_states() 365 366 ccd_was_enabled = self.ccd_enabled 367 self.cr50.ccd_enable(raise_error=False) 368 self.ccd_enabled = self.cr50.ccd_is_enabled() 369 # If the first run had ccd disabled, and the test was able to enable 370 # ccd, run through the states again to make sure there are no issues 371 # come up when ccd is enabled. 372 if not ccd_was_enabled and self.ccd_enabled: 373 # Reboot the EC to reset the device 374 self.ec.reboot() 375 self.run_through_power_states() 376 377 if self.all_errors: 378 raise error.TestFail('Unexpected IRQ counts: %s' % self.all_errors) 379