276 lines
10 KiB
Python
276 lines
10 KiB
Python
# 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 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'
|
|
|
|
|
|
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'),
|
|
]
|
|
|
|
|
|
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.
|
|
|
|
"""
|
|
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
|