Debug Android and Linux suspend and resume

Debug Android and Linux suspend and resume

Added by raymond wang, last edited by raymond
wang on Mar 08, 2013 (view change)



积攒了一些关于调试Android和Linux下面的suspend 和 resume的经验， 在这里和大家分享一下。

希望可以有些帮助， （下面没有写Android专用的， 就是Linux通用的）。

1. no_console_suspend

在kernel启动参数里面加上no_console_suspend， 这个是最基本的， 因为kernel在把console suspend掉以后， 不管里面出了什么事情， 从串口上都看不到。 大部分在suspend/resume时候的死机都可以通过串口看到kernel Panic的信息， 这样才会知道是哪里出了问题。因为有的时候resume出错， 或者suspend到很后面出错的console不加这个参数都看不到。

2. initcall_debug

这个也许知道的人不多， 其实有的时候你不知道哪个driver在suspend/resume的时候出错的时候，很迷茫， 就想在哪里加上一些调试信息来看看是哪里的driver， 其实有些时候加的不合适的话， 会看不到很多有用的信息。其实kernel本身已经有这样的功能了（只不过不是很人性化）。

1

2

3

4

echo 1 > /sys/module/kernel/parameters/initcall_debug

echo 9 > /proc/sys/kernel/printk

<br />

第一条命令是打开initcall_debug， 这个是所有的kernel都会有的， 也可以在启动参数里面加initcall_debug来默认打开这个参数， 这样可以调试系统启动。

因为这些信息都是KERN_DEBUG级别的， 所以需要提高printk的级别才可以看到， 要不然suspend/resume的时候死掉了，你就没有机会看到这些信息了。

3. suspend_test

这个方法可以用rtc这种软件的方式来做循环的suspend/resume， 尽管对于Android这样并不是很足够， （你得模拟一个POWER_KEY上去才够）， 但是对于调试Driver的稳定性， 还是有一定用处的。 不要以为suspend了几次可以， 那么就可以通过几千次的测试。 这个suspend是5秒钟用RTC唤醒， 然后对于Android, 5秒钟又会自动睡下去， 但是对于通用Linux， 你得写个小脚本来让他一会再睡下去， 或许这个工具比较有用rtcwakeup（google rtcwakeup)。

使用方法：

编译一个有这个功能的kernel， make menuconfig 以后选上

CONFIG_PM_DEBBUG=y

CONFIG_PM_TEST_SUSPEND=y

这两个选项

烧写新的kernel，然后打开你需要测试的东东， 比如WIFI，3G

echo “core” > /sys/power/pm_test

echo “mem” > /sys/power/state

这样， 它就会循环休眠和唤醒了。

4. wakelock

轮到Android的调试了， Android里面和Power相关最大的就是wakelock, 有时候会碰到睡不下去，或者睡到最后弹起来的问题， 就是wakelock引起的，或者说是wakelock的使用者引起的。

怎么调试呢，用一下两个：

echo 15 > /sys/module/wakelock/parameters/debug_mask

echo 15 > /sys/module/userwakelock/parameters/debug_mask

15是代表16进制的F， 在wakelock里面就是把所有的debug信息打开， 起码现在是。如果以后不够了，估计得输入255.

这样你能看到kernel和frameworks层对于wakelock的操作， 申请和释放。 这样看申请和释放成对否就可以了。注意： wakelock有一种是timeout的， 就是说多少毫秒以后， 会自动释放， 对于这些wakelock， 申请和释放可能是不成对的。。

5. power.0

有的时候你会看到系统suspend到了最后， 然后遇到power.0 suspend失败，然后整个系统都又resume起来了。 这个是android专有的，因为power.0是android注册到suspend最后的一个回调， 它会在CPU进入suspend之前检查一下有没有wakelock， 如果这时候还有没有释放的wakelock， 那么它会返回-EBUSY然后导致整个suspend失败。 调试这个问题的方法就是把上面wakelock的debug信息打开， 然后看看是哪个家伙去申请了wakelock，然后干掉它。

这个错误的错误信息大概是这样的：

pm_noirq_op(): platform_pm_suspend_noirq+0×0/0×38 returns -11

PM: Device power.0 failed to suspend late: error -11

6. earlysuspend

差点忘掉这个哥们， android里面另外一个pm相关的大东东， 同样可以加：

echo 15 > /sys/module/earlysuspend/parameters/debug_mask

来把相关的debug信息打印出来， 比如那个earlysuspend要被call之类的。

7. suspend/resume time.

有的时候你要调试suspend/resume的时间太慢的问题。 一种方法是用initcall_debug， 然后把printk的时间戳打上， 然后看哪个很慢。

但是这样会让你的生活很枯燥：）

我有一个patch，专门用来调试这个问题的，但是upstream不接受， 说非要用这种折磨人的方法才行， 但是如果你想用可以下下来打上去用一下。

地址在这里:http://www.spinics.net/lists/linux-pm/msg24063.html

用法是, 打上这个PATCH以后, 在KERNEL里面选择上PM_DEBUG， SUSPEND_DEVICE_TIME_DEBUG 这两个选项。

然后

echo 微秒 > /sys/power/device_suspend_time_threshold

比如

echo 50000 > /sys/power/device_suspend_time_threshold

注意这里是微秒哦。。。 它会把在suspend/resume的时候慢的那些driver打出来，然后你去干掉它。。。

From: Zhang Jiejing <jiejing.zhang@xxxxxxxxxxxxx>

This patch add function to check each device's suspend time
consumption. If any driver takes more time that the threshold (default
0.5 ms), it will print a warnning message including the device and bus
name on the console.  You can change the threshold on-the-fly by
modify file '/sys/power/device_suspend_time_threshold' to adjust this
value,the unit is in microsecond.

The output is like:
PM: device (bus)   :(device name) suspend/resume too slow, takes (time) msencs.
PM: device platform:soc-audio.2 suspend too slow, takes          606.696 msecs
PM: device platform:mxc_sdc_fb.1 suspend too slow, takes         7.708 msecs

Signed-off-by: Zhang Jiejing <jiejing.zhang@xxxxxxxxxxxxx>
---
drivers/base/power/main.c  |   40 +++++++++++++++++++++++++++++++++++++++-
drivers/base/power/power.h |    3 +++
kernel/power/Kconfig       |   15 +++++++++++++++
kernel/power/main.c        |   32 ++++++++++++++++++++++++++++++++
4 files changed, 89 insertions(+), 1 deletions(-)

diff --git a/drivers/base/power/main.c b/drivers/base/power/main.c
index 052dc53..000243c 100644
--- a/drivers/base/power/main.c
+++ b/drivers/base/power/main.c
@@ -178,6 +178,40 @@ static void initcall_debug_report(struct device *dev, ktime_t calltime,
}
}

+#ifdef CONFIG_SUSPEND_DEVICE_TIME_DEBUG
+static void suspend_time_debug_start(ktime_t *start)
+{
+	*start = ktime_get();
+}
+
+static void suspend_time_debug_report(const char *name, struct device *dev,
+				      ktime_t starttime)
+{
+	ktime_t rettime;
+	s64 usecs64;
+	int usecs;
+
+	if (!dev->driver)
+		return;
+
+	rettime = ktime_get();
+	usecs64 = ktime_to_us(ktime_sub(rettime, starttime));
+	usecs = usecs64;
+	if (usecs == 0)
+		usecs = 1;
+
+	if (device_suspend_time_threshold
+	    && usecs > device_suspend_time_threshold)
+		pr_info("PM: device %s:%s %s too slow, it takes \t %ld.%03ld mses\n",
+			dev->bus->name, dev_name(dev), name,
+			usecs / USEC_PER_MSEC, usecs % USEC_PER_MSEC);
+}
+#else
+static void suspend_time_debug_start(ktime_t *start) {}
+static void suspend_time_debug_report(const char *name, struct device *dev,
+				      ktime_t starttime) {}
+#endif /* CONFIG_SUSPEND_DEVICE_TIME_DEBUG */
+
/**
* dpm_wait - Wait for a PM operation to complete.
* @dev: Device to wait for.
@@ -214,7 +248,7 @@ static int pm_op(struct device *dev,
pm_message_t state)
{
int error = 0;
-	ktime_t calltime;
+	ktime_t calltime, starttime;

calltime = initcall_debug_start(dev);

@@ -222,13 +256,17 @@ static int pm_op(struct device *dev,
#ifdef CONFIG_SUSPEND
case PM_EVENT_SUSPEND:
if (ops->suspend) {
+			suspend_time_debug_start(&starttime);
error = ops->suspend(dev);
+			suspend_time_debug_report("suspend", dev, starttime);
suspend_report_result(ops->suspend, error);
}
break;
case PM_EVENT_RESUME:
if (ops->resume) {
+			suspend_time_debug_start(&starttime);
error = ops->resume(dev);
+			suspend_time_debug_report("resume", dev, starttime);
suspend_report_result(ops->resume, error);
}
break;
diff --git a/drivers/base/power/power.h b/drivers/base/power/power.h
index f2a25f1..72d5963 100644
--- a/drivers/base/power/power.h
+++ b/drivers/base/power/power.h
@@ -18,6 +18,9 @@ extern int pm_async_enabled;
/* drivers/base/power/main.c */
extern struct list_head dpm_list;	/* The active device list */

+/* driver/base/power/main.c */
+extern int device_suspend_time_threshold;
+
static inline struct device *to_device(struct list_head *entry)
{
return container_of(entry, struct device, power.entry);
diff --git a/kernel/power/Kconfig b/kernel/power/Kconfig
index 4603f08..9b82c4b 100644
--- a/kernel/power/Kconfig
+++ b/kernel/power/Kconfig
@@ -87,6 +87,21 @@ config PM_SLEEP
def_bool y
depends on SUSPEND || HIBERNATION || XEN_SAVE_RESTORE

+config SUSPEND_DEVICE_TIME_DEBUG
+        bool "Warnning device suspend/resume takes too much time"
+	depends on SUSPEND && PM_DEBUG
+	default n
+	---help---
+
+	This option will enable a timing function to check each device
+        suspend time consumption, If the device takes more time that
+        the threshold (default 0.5 ms), it will print the device and
+        bus name on the console.  You can change the threshold
+        on-the-fly by modify "/sys/power/device_suspend_time_threshold"
+        the unit is in microsecond.
+
+	This options only for debug proprose, If in doubt, say N.
+
config PM_SLEEP_SMP
def_bool y
depends on SMP
diff --git a/kernel/power/main.c b/kernel/power/main.c
index 8eaba5f..d2e734f 100644
--- a/kernel/power/main.c
+++ b/kernel/power/main.c
@@ -297,12 +297,44 @@ power_attr(pm_trace_dev_match);

#endif /* CONFIG_PM_TRACE */

+#ifdef CONFIG_SUSPEND_DEVICE_TIME_DEBUG
+/*
+ * threshold of device suspend time consumption in microsecond(0.5ms), the
+ * driver suspend/resume time longer than this threshold will be
+ * print to console, 0 to disable */
+int device_suspend_time_threshold = 500;
+
+static ssize_t
+device_suspend_time_threshold_show(struct kobject *kobj,
+				   struct kobj_attribute *attr, char *buf)
+{
+	return sprintf(buf, "%d\n", device_suspend_time_threshold);
+}
+
+static ssize_t
+device_suspend_time_threshold_store(struct kobject *kobj,
+				    struct kobj_attribute *attr,
+				    const char *buf, size_t n)
+{
+	int val;
+	if (sscanf(buf, "%d", &val) > 0) {
+		device_suspend_time_threshold = val;
+		return n;
+	}
+	return -EINVAL;
+}
+power_attr(device_suspend_time_threshold);
+#endif
+
static struct attribute * g[] = {
&state_attr.attr,
#ifdef CONFIG_PM_TRACE
&pm_trace_attr.attr,
&pm_trace_dev_match_attr.attr,
#endif
+#ifdef CONFIG_SUSPEND_DEVICE_TIME_DEBUG
+	&device_suspend_time_threshold_attr.attr,
+#endif
#ifdef CONFIG_PM_SLEEP
&pm_async_attr.attr,
&wakeup_count_attr.attr,
--
1.7.1

Add Labels

Add
Comment