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