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