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 """Provides utility methods for controlling powerd in ChromiumOS.""" 6 7 import errno 8 import fcntl 9 import logging 10 import multiprocessing 11 import os 12 import time 13 14 import common 15 from autotest_lib.client.cros import rtc 16 from autotest_lib.client.cros import upstart 17 18 SYSFS_POWER_STATE = '/sys/power/state' 19 SYSFS_WAKEUP_COUNT = '/sys/power/wakeup_count' 20 21 PAUSE_ETHERNET_HOOK_FILE = '/run/autotest_pause_ethernet_hook' 22 pause_ethernet_fd = 0 23 24 25 class SuspendFailure(Exception): 26 """Base class for a failure during a single suspend/resume cycle.""" 27 pass 28 29 30 class SuspendTimeout(SuspendFailure): 31 """Suspend took too long, got wakeup event (RTC tick) before it was done.""" 32 pass 33 34 35 class KernelError(SuspendFailure): 36 """Kernel problem encountered during suspend/resume. 37 38 Whitelist is an array of a 2-entry tuples consisting of (source regexp, text 39 regexp). For example, kernel output might look like, 40 41 [ 597.079950] WARNING: CPU: 0 PID: 21415 at \ 42 <path>/v3.18/drivers/gpu/drm/i915/intel_pm.c:3687 \ 43 skl_update_other_pipe_wm+0x136/0x18a() 44 [ 597.079962] WARN_ON(!wm_changed) 45 46 source regexp should match first line above while text regexp can match 47 up to 2 lines below the source. Note timestamps are stripped prior to 48 comparing regexp. 49 """ 50 WHITELIST = [ 51 # crosbug.com/37594: debug tracing clock desync we don't care about 52 (r'kernel/trace/ring_buffer.c:\d+ rb_reserve_next_event', 53 r'Delta way too big!'), 54 # TODO(crosbug.com/p/52008): Remove from whitelist once watermark 55 # implementation has landed. 56 (r'v3.18/\S+/intel_pm.c:\d+ skl_update_other_pipe_wm', 57 r'WARN_ON\(\!wm_changed\)') 58 ] 59 60 61 class FirmwareError(SuspendFailure): 62 """String 'ERROR' found in firmware log after resume.""" 63 WHITELIST = [ 64 # crosbug.com/36762: no one knows, but it has always been there 65 ('^stumpy', r'PNP: 002e\.4 70 irq size: 0x0000000001 not assigned'), 66 # crbug.com/221538: no one knows what ME errors mean anyway 67 ('^parrot', r'ME failed to respond'), 68 # b/64684441: eve SKU without eMMC 69 ('^eve', r'Card did not respond to voltage select!'), 70 ] 71 72 73 class SpuriousWakeupError(SuspendFailure): 74 """Received spurious wakeup while suspending or woke before schedule.""" 75 S3_WHITELIST = [ # (<board>, <eventlog wake source>, <syslog wake source>) 76 # crbug.com/220014: spurious trackpad IRQs 77 ('^link', 'Wake Source | GPIO | 12', ''), 78 # crbug.com/345327: unknown, probably same as crbug.com/290923 79 ('^x86-alex', '', ''), # alex can report neither, blanket ignore 80 # crbug.com/355106: unknown, possibly related to crbug.com/290923 81 ('^lumpy|^parrot', '', 'PM1_STS: WAK PWRBTN'), 82 ] 83 S0_WHITELIST = [ # (<board>, <kernel wake source>) 84 # crbug.com/290923: spurious keyboard IRQ, believed to be from Servo 85 ('^x86-alex|^lumpy|^parrot|^butterfly', 'serio0'), 86 # crosbug.com/p/46140: battery event caused by MKBP 87 ('^elm|^oak', 'spi32766.0'), 88 ] 89 90 class MemoryError(SuspendFailure): 91 """memory_suspend_test found memory corruption.""" 92 pass 93 94 95 class SuspendNotAllowed(SuspendFailure): 96 """Suspend was not allowed to be performed.""" 97 pass 98 99 100 class S0ixResidencyNotChanged(SuspendFailure): 101 """power_SuspendStress test found CPU/SoC is unable to idle properly 102 when suspended to S0ix. """ 103 pass 104 105 def prepare_wakeup(seconds): 106 """Prepare the device to wake up from an upcoming suspend. 107 108 @param seconds: The number of seconds to allow the device to suspend. 109 """ 110 # May cause DUT not wake from sleep if the suspend time is 1 second. 111 # It happens when the current clock (floating point) is close to the 112 # next integer, as the RTC sysfs interface only accepts integers. 113 # Make sure it is larger than or equal to 2. 114 assert seconds >= 2 115 wakeup_count = read_wakeup_count() 116 alarm = int(rtc.get_seconds() + seconds) 117 logging.debug('Suspend for %d seconds, wakealarm = %d', seconds, alarm) 118 rtc.set_wake_alarm(alarm) 119 return (alarm, wakeup_count) 120 121 122 def check_wakeup(alarm): 123 """Verify that the device did not wakeup early. 124 125 @param alarm: The time at which the device was expected to wake up. 126 """ 127 now = rtc.get_seconds() 128 if now < alarm: 129 logging.error('Woke up early at %d', now) 130 raise SpuriousWakeupError('Woke from suspend early') 131 132 133 def do_suspend(suspend_seconds, delay_seconds=0): 134 """Do a suspend using the power manager. 135 136 Wait for |delay_seconds|, suspend the system to RAM (S3), waking up again 137 after having been suspended for |suspend_seconds|, using the 138 powerd_dbus_suspend program. Function will block until suspend/resume 139 has completed or failed. Returns the wake alarm time from the RTC as epoch. 140 141 @param suspend_seconds: Number of seconds to suspend the DUT. 142 @param delay_seconds: Number of seconds wait before suspending the DUT. 143 144 """ 145 146 # stop check_ethernet.hook from running until the test exits 147 global pause_ethernet_fd 148 if pause_ethernet_fd == 0: 149 # we don't write to the file - but we might need to create it. 150 pause_ethernet_fd = open(PAUSE_ETHERNET_HOOK_FILE,'a+') 151 152 if pause_ethernet_fd > 0: 153 try: 154 # this is a blocking call unless an error occurs. 155 fcntl.flock(pause_ethernet_fd, fcntl.LOCK_SH) 156 except IOError: 157 pass 158 159 alarm, wakeup_count = prepare_wakeup(suspend_seconds) 160 upstart.ensure_running('powerd') 161 command = ('/usr/bin/powerd_dbus_suspend --delay=%d --timeout=30 ' 162 '--wakeup_count=%d') % (delay_seconds, wakeup_count) 163 logging.info("Running '%s'", command) 164 os.system(command) 165 check_wakeup(alarm) 166 return alarm 167 168 169 def suspend_bg_for_dark_resume(delay_seconds=0): 170 """Do a non-blocking indefinite suspend using power manager. ONLY USE THIS 171 IF YOU ARE ABSOLUTELY CERTAIN YOU NEED TO. 172 173 Wait for |delay_seconds|, then suspend to RAM (S3). This does not set an RTC 174 alarm and does not pass an external wakeup count. It is meant to be used for 175 dark resume testing, where the server-side API exposes it in such a fashion 176 that the DUT will be woken by the server no matter how the test is exited. 177 178 @param delay_seconds: Number of seconds wait before suspending the DUT. 179 180 """ 181 upstart.ensure_running('powerd') 182 command = ('/usr/bin/powerd_dbus_suspend --delay=%d ' 183 '--timeout=30') % delay_seconds 184 logging.info("Running '%s'", command) 185 process = multiprocessing.Process(target=os.system, args=(command,)) 186 process.start() 187 188 189 def kernel_suspend(seconds, state='mem'): 190 """Do a kernel suspend. 191 192 Suspend the system to @state, waking up again after |seconds|, by directly 193 writing to /sys/power/state. Function will block until suspend/resume has 194 completed or failed. 195 196 @param seconds: The number of seconds to suspend the device. 197 @param state: power state to suspend to. DEFAULT mem. 198 """ 199 alarm, wakeup_count = prepare_wakeup(seconds) 200 logging.debug('Saving wakeup count: %d', wakeup_count) 201 write_wakeup_count(wakeup_count) 202 try: 203 logging.info('Suspending at %d', rtc.get_seconds()) 204 with open(SYSFS_POWER_STATE, 'w') as sysfs_file: 205 sysfs_file.write(state) 206 except IOError as e: 207 logging.exception('Writing to %s failed', SYSFS_POWER_STATE) 208 if e.errno == errno.EBUSY and rtc.get_seconds() >= alarm: 209 # The kernel returns EBUSY if it has to abort because 210 # another wakeup fires before we've reached suspend. 211 raise SpuriousWakeupError('Received spurious wakeup in kernel.') 212 else: 213 # Some driver probably failed to suspend properly. 214 # A hint as to what failed is in errno. 215 raise KernelError('Suspend failed: %s' % e.strerror) 216 else: 217 logging.info('Woke from suspend at %d', rtc.get_seconds()) 218 logging.debug('New wakeup count: %d', read_wakeup_count()) 219 check_wakeup(alarm) 220 221 222 def idle_suspend(seconds): 223 """ 224 Wait for the system to suspend to RAM (S3), scheduling the RTC to wake up 225 |seconds| after this function was called. Caller must ensure that the system 226 will idle-suspend in time for this to happen. Returns the wake alarm time 227 from the RTC as epoch. 228 229 @param seconds: The number of seconds before wakeup. 230 """ 231 alarm, _ = prepare_wakeup(seconds) 232 while rtc.get_seconds() < alarm: 233 time.sleep(0.2) 234 235 # tell powerd something happened, or it will immediately idle-suspend again 236 # TODO: switch to cros.power_utils#call_powerd_dbus_method once this 237 # horrible mess with the WiFi tests and this file's imports is solved 238 logging.debug('Simulating user activity after idle suspend...') 239 os.system('dbus-send --type=method_call --system ' 240 '--dest=org.chromium.PowerManager /org/chromium/PowerManager ' 241 'org.chromium.PowerManager.HandleUserActivity') 242 243 return alarm 244 245 246 def memory_suspend(seconds, size=0): 247 """Do a memory suspend. 248 249 Suspend the system to RAM (S3), waking up again after |seconds|, using 250 the memory_suspend_test tool. Function will block until suspend/resume has 251 completed or failed. Returns the wake alarm time from the RTC as epoch. 252 253 @param seconds: The number of seconds to suspend the device. 254 @param size: Amount of memory to allocate, in bytes. 255 Set to 0 to let memory_suspend_test determine amount of memory. 256 """ 257 # since we cannot have utils.system_output in here, we need a workaround 258 output = '/tmp/memory_suspend_output' 259 alarm, wakeup_count = prepare_wakeup(seconds) 260 status = os.system('/usr/bin/memory_suspend_test --wakeup_count=%d ' 261 '--size=%d > %s' % (wakeup_count, size, output)) 262 status = os.WEXITSTATUS(status) 263 if status == 2: 264 logging.error('memory_suspend_test found the following errors:') 265 for line in open(output, 'r'): 266 logging.error(line) 267 raise MemoryError('Memory corruption found after resume') 268 elif status == 1: 269 raise SuspendFailure('Failure in powerd_suspend during memory test') 270 elif status: 271 raise SuspendFailure('Unknown failure in memory_suspend_test (crash?)') 272 check_wakeup(alarm) 273 return alarm 274 275 276 def read_wakeup_count(): 277 """ 278 Retrieves the current value of /sys/power/wakeup_count. 279 """ 280 with open(SYSFS_WAKEUP_COUNT) as sysfs_file: 281 return int(sysfs_file.read().rstrip('\n')) 282 283 284 def write_wakeup_count(wakeup_count): 285 """Writes a value to /sys/power/wakeup_count. 286 287 @param wakeup_count: The wakeup count value to write. 288 """ 289 try: 290 with open(SYSFS_WAKEUP_COUNT, 'w') as sysfs_file: 291 sysfs_file.write(str(wakeup_count)) 292 except IOError as e: 293 if (e.errno == errno.EINVAL and read_wakeup_count() != wakeup_count): 294 raise SpuriousWakeupError('wakeup_count changed before suspend') 295 else: 296 raise 297
