blob: 188afc0c5ebc06b6191cc5c9e5f45312aae8449e [file] [log] [blame]
# 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, logging, os, rtc, time, upstart
SYSFS_POWER_STATE = '/sys/power/state'
SYSFS_WAKEUP_COUNT = '/sys/power/wakeup_count'
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 = [
# 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!'),
]
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'),
]
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'),
]
class MemoryError(SuspendFailure):
"""memory_suspend_test found memory corruption."""
pass
class SuspendNotAllowed(SuspendFailure):
"""Suspend was not allowed to be performed."""
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.
"""
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 kernel_suspend(seconds):
"""Do a kernel suspend.
Suspend the system to RAM (S3), 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.
"""
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('mem')
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