| # Copyright (c) 2012 The Chromium OS Authors. All rights reserved. |
| # Use of this source code is governed by a BSD-style license that can be |
| # found in the LICENSE file. |
| |
| """Provides utility methods for controlling powerd in ChromiumOS.""" |
| |
| import errno |
| import fcntl |
| import logging |
| import multiprocessing |
| import os |
| import time |
| |
| import common |
| from autotest_lib.client.cros import rtc |
| from autotest_lib.client.cros import upstart |
| |
| SYSFS_POWER_STATE = '/sys/power/state' |
| SYSFS_WAKEUP_COUNT = '/sys/power/wakeup_count' |
| |
| PAUSE_ETHERNET_HOOK_FILE = '/run/autotest_pause_ethernet_hook' |
| pause_ethernet_fd = 0 |
| |
| |
| class SuspendFailure(Exception): |
| """Base class for a failure during a single suspend/resume cycle.""" |
| pass |
| |
| |
| class SuspendTimeout(SuspendFailure): |
| """Suspend took too long, got wakeup event (RTC tick) before it was done.""" |
| pass |
| |
| |
| class KernelError(SuspendFailure): |
| """Kernel problem encountered during suspend/resume. |
| |
| Whitelist is an array of a 2-entry tuples consisting of (source regexp, text |
| regexp). For example, kernel output might look like, |
| |
| [ 597.079950] WARNING: CPU: 0 PID: 21415 at \ |
| <path>/v3.18/drivers/gpu/drm/i915/intel_pm.c:3687 \ |
| skl_update_other_pipe_wm+0x136/0x18a() |
| [ 597.079962] WARN_ON(!wm_changed) |
| |
| source regexp should match first line above while text regexp can match |
| up to 2 lines below the source. Note timestamps are stripped prior to |
| comparing regexp. |
| """ |
| WHITELIST = [ |
| # crosbug.com/37594: debug tracing clock desync we don't care about |
| (r'kernel/trace/ring_buffer.c:\d+ rb_reserve_next_event', |
| r'Delta way too big!'), |
| # TODO(crosbug.com/p/52008): Remove from whitelist once watermark |
| # implementation has landed. |
| (r'v3.18/\S+/intel_pm.c:\d+ skl_update_other_pipe_wm', |
| r'WARN_ON\(\!wm_changed\)') |
| ] |
| |
| |
| class FirmwareError(SuspendFailure): |
| """String 'ERROR' found in firmware log after resume.""" |
| WHITELIST = [ |
| # crosbug.com/36762: no one knows, but it has always been there |
| ('^stumpy', r'PNP: 002e\.4 70 irq size: 0x0000000001 not assigned'), |
| # crbug.com/221538: no one knows what ME errors mean anyway |
| ('^parrot', r'ME failed to respond'), |
| # b/64684441: eve SKU without eMMC |
| ('^eve', r'Card did not respond to voltage select!'), |
| ] |
| |
| |
| class SpuriousWakeupError(SuspendFailure): |
| """Received spurious wakeup while suspending or woke before schedule.""" |
| S3_WHITELIST = [ # (<board>, <eventlog wake source>, <syslog wake source>) |
| # crbug.com/220014: spurious trackpad IRQs |
| ('^link', 'Wake Source | GPIO | 12', ''), |
| # crbug.com/345327: unknown, probably same as crbug.com/290923 |
| ('^x86-alex', '', ''), # alex can report neither, blanket ignore |
| # crbug.com/355106: unknown, possibly related to crbug.com/290923 |
| ('^lumpy|^parrot', '', 'PM1_STS: WAK PWRBTN'), |
| ] |
| S0_WHITELIST = [ # (<board>, <kernel wake source>) |
| # crbug.com/290923: spurious keyboard IRQ, believed to be from Servo |
| ('^x86-alex|^lumpy|^parrot|^butterfly', 'serio0'), |
| # crosbug.com/p/46140: battery event caused by MKBP |
| ('^elm|^oak', 'spi32766.0'), |
| ] |
| |
| class MemoryError(SuspendFailure): |
| """memory_suspend_test found memory corruption.""" |
| pass |
| |
| |
| class SuspendNotAllowed(SuspendFailure): |
| """Suspend was not allowed to be performed.""" |
| pass |
| |
| |
| class S0ixResidencyNotChanged(SuspendFailure): |
| """power_SuspendStress test found CPU/SoC is unable to idle properly |
| when suspended to S0ix. """ |
| pass |
| |
| def prepare_wakeup(seconds): |
| """Prepare the device to wake up from an upcoming suspend. |
| |
| @param seconds: The number of seconds to allow the device to suspend. |
| """ |
| # May cause DUT not wake from sleep if the suspend time is 1 second. |
| # It happens when the current clock (floating point) is close to the |
| # next integer, as the RTC sysfs interface only accepts integers. |
| # Make sure it is larger than or equal to 2. |
| assert seconds >= 2 |
| wakeup_count = read_wakeup_count() |
| alarm = int(rtc.get_seconds() + seconds) |
| logging.debug('Suspend for %d seconds, wakealarm = %d', seconds, alarm) |
| rtc.set_wake_alarm(alarm) |
| return (alarm, wakeup_count) |
| |
| |
| def check_wakeup(alarm): |
| """Verify that the device did not wakeup early. |
| |
| @param alarm: The time at which the device was expected to wake up. |
| """ |
| now = rtc.get_seconds() |
| if now < alarm: |
| logging.error('Woke up early at %d', now) |
| raise SpuriousWakeupError('Woke from suspend early') |
| |
| |
| def do_suspend(suspend_seconds, delay_seconds=0): |
| """Do a suspend using the power manager. |
| |
| Wait for |delay_seconds|, suspend the system to RAM (S3), waking up again |
| after having been suspended for |suspend_seconds|, using the |
| powerd_dbus_suspend program. Function will block until suspend/resume |
| has completed or failed. Returns the wake alarm time from the RTC as epoch. |
| |
| @param suspend_seconds: Number of seconds to suspend the DUT. |
| @param delay_seconds: Number of seconds wait before suspending the DUT. |
| |
| """ |
| |
| # stop check_ethernet.hook from running until the test exits |
| global pause_ethernet_fd |
| if pause_ethernet_fd == 0: |
| # we don't write to the file - but we might need to create it. |
| pause_ethernet_fd = open(PAUSE_ETHERNET_HOOK_FILE,'a+') |
| |
| if pause_ethernet_fd > 0: |
| try: |
| # this is a blocking call unless an error occurs. |
| fcntl.flock(pause_ethernet_fd, fcntl.LOCK_SH) |
| except IOError: |
| pass |
| |
| alarm, wakeup_count = prepare_wakeup(suspend_seconds) |
| upstart.ensure_running('powerd') |
| command = ('/usr/bin/powerd_dbus_suspend --delay=%d --timeout=30 ' |
| '--wakeup_count=%d') % (delay_seconds, wakeup_count) |
| logging.info("Running '%s'", command) |
| os.system(command) |
| check_wakeup(alarm) |
| return alarm |
| |
| |
| def suspend_bg_for_dark_resume(delay_seconds=0): |
| """Do a non-blocking indefinite suspend using power manager. ONLY USE THIS |
| IF YOU ARE ABSOLUTELY CERTAIN YOU NEED TO. |
| |
| Wait for |delay_seconds|, then suspend to RAM (S3). This does not set an RTC |
| alarm and does not pass an external wakeup count. It is meant to be used for |
| dark resume testing, where the server-side API exposes it in such a fashion |
| that the DUT will be woken by the server no matter how the test is exited. |
| |
| @param delay_seconds: Number of seconds wait before suspending the DUT. |
| |
| """ |
| upstart.ensure_running('powerd') |
| command = ('/usr/bin/powerd_dbus_suspend --delay=%d ' |
| '--timeout=30') % delay_seconds |
| logging.info("Running '%s'", command) |
| process = multiprocessing.Process(target=os.system, args=(command,)) |
| process.start() |
| |
| |
| def kernel_suspend(seconds, state='mem'): |
| """Do a kernel suspend. |
| |
| Suspend the system to @state, waking up again after |seconds|, by directly |
| writing to /sys/power/state. Function will block until suspend/resume has |
| completed or failed. |
| |
| @param seconds: The number of seconds to suspend the device. |
| @param state: power state to suspend to. DEFAULT mem. |
| """ |
| alarm, wakeup_count = prepare_wakeup(seconds) |
| logging.debug('Saving wakeup count: %d', wakeup_count) |
| write_wakeup_count(wakeup_count) |
| try: |
| logging.info('Suspending at %d', rtc.get_seconds()) |
| with open(SYSFS_POWER_STATE, 'w') as sysfs_file: |
| sysfs_file.write(state) |
| except IOError as e: |
| logging.exception('Writing to %s failed', SYSFS_POWER_STATE) |
| if e.errno == errno.EBUSY and rtc.get_seconds() >= alarm: |
| # The kernel returns EBUSY if it has to abort because |
| # another wakeup fires before we've reached suspend. |
| raise SpuriousWakeupError('Received spurious wakeup in kernel.') |
| else: |
| # Some driver probably failed to suspend properly. |
| # A hint as to what failed is in errno. |
| raise KernelError('Suspend failed: %s' % e.strerror) |
| else: |
| logging.info('Woke from suspend at %d', rtc.get_seconds()) |
| logging.debug('New wakeup count: %d', read_wakeup_count()) |
| check_wakeup(alarm) |
| |
| |
| def idle_suspend(seconds): |
| """ |
| Wait for the system to suspend to RAM (S3), scheduling the RTC to wake up |
| |seconds| after this function was called. Caller must ensure that the system |
| will idle-suspend in time for this to happen. Returns the wake alarm time |
| from the RTC as epoch. |
| |
| @param seconds: The number of seconds before wakeup. |
| """ |
| alarm, _ = prepare_wakeup(seconds) |
| while rtc.get_seconds() < alarm: |
| time.sleep(0.2) |
| |
| # tell powerd something happened, or it will immediately idle-suspend again |
| # TODO: switch to cros.power_utils#call_powerd_dbus_method once this |
| # horrible mess with the WiFi tests and this file's imports is solved |
| logging.debug('Simulating user activity after idle suspend...') |
| os.system('dbus-send --type=method_call --system ' |
| '--dest=org.chromium.PowerManager /org/chromium/PowerManager ' |
| 'org.chromium.PowerManager.HandleUserActivity') |
| |
| return alarm |
| |
| |
| def memory_suspend(seconds, size=0): |
| """Do a memory suspend. |
| |
| Suspend the system to RAM (S3), waking up again after |seconds|, using |
| the memory_suspend_test tool. Function will block until suspend/resume has |
| completed or failed. Returns the wake alarm time from the RTC as epoch. |
| |
| @param seconds: The number of seconds to suspend the device. |
| @param size: Amount of memory to allocate, in bytes. |
| Set to 0 to let memory_suspend_test determine amount of memory. |
| """ |
| # since we cannot have utils.system_output in here, we need a workaround |
| output = '/tmp/memory_suspend_output' |
| alarm, wakeup_count = prepare_wakeup(seconds) |
| status = os.system('/usr/bin/memory_suspend_test --wakeup_count=%d ' |
| '--size=%d > %s' % (wakeup_count, size, output)) |
| status = os.WEXITSTATUS(status) |
| if status == 2: |
| logging.error('memory_suspend_test found the following errors:') |
| for line in open(output, 'r'): |
| logging.error(line) |
| raise MemoryError('Memory corruption found after resume') |
| elif status == 1: |
| raise SuspendFailure('Failure in powerd_suspend during memory test') |
| elif status: |
| raise SuspendFailure('Unknown failure in memory_suspend_test (crash?)') |
| check_wakeup(alarm) |
| return alarm |
| |
| |
| def read_wakeup_count(): |
| """ |
| Retrieves the current value of /sys/power/wakeup_count. |
| """ |
| with open(SYSFS_WAKEUP_COUNT) as sysfs_file: |
| return int(sysfs_file.read().rstrip('\n')) |
| |
| |
| def write_wakeup_count(wakeup_count): |
| """Writes a value to /sys/power/wakeup_count. |
| |
| @param wakeup_count: The wakeup count value to write. |
| """ |
| try: |
| with open(SYSFS_WAKEUP_COUNT, 'w') as sysfs_file: |
| sysfs_file.write(str(wakeup_count)) |
| except IOError as e: |
| if (e.errno == errno.EINVAL and read_wakeup_count() != wakeup_count): |
| raise SpuriousWakeupError('wakeup_count changed before suspend') |
| else: |
| raise |