• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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 time
12
13import common
14from autotest_lib.client.cros import rtc
15from autotest_lib.client.cros import upstart
16
17SYSFS_POWER_STATE = '/sys/power/state'
18SYSFS_WAKEUP_COUNT = '/sys/power/wakeup_count'
19
20
21class SuspendFailure(Exception):
22    """Base class for a failure during a single suspend/resume cycle."""
23    pass
24
25
26class SuspendTimeout(SuspendFailure):
27    """Suspend took too long, got wakeup event (RTC tick) before it was done."""
28    pass
29
30
31class 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
57class 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
67class 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
84class MemoryError(SuspendFailure):
85    """memory_suspend_test found memory corruption."""
86    pass
87
88
89class SuspendNotAllowed(SuspendFailure):
90    """Suspend was not allowed to be performed."""
91    pass
92
93
94class S0ixResidencyNotChanged(SuspendFailure):
95    """power_SuspendStress test found CPU/SoC is unable to idle properly
96    when suspended to S0ix. """
97    pass
98
99def 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
116def 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
127def 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
149def 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
169def 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
202def 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
226def 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
256def 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
264def 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