這段錯誤訊息 PM: Some devices failed to suspend 可能是wakeup_event的問題

會發生Error Message : [ 365.610079] PM: Some devices failed to suspend
關鍵是來自這段程式碼, 所以是wakeup_event的問題, 而非devices

if (pm_wakeup_pending()) {
   printk(KERN_ERR "TTTTTT __device_suspend(),  Yes pm_wakeup_pending ..\n");    <===我加的 message
   async_error = -EBUSY;
   goto Complete;
}

Android手持系統頻繁的進出suspend/resume狀況,
因此需要 pm_wakeup_pending() 機制, 用來檢查進入這段時間是否有被喚醒的事件發生
讓我們看程式碼

/**
* pm_wakeup_pending - Check if power transition in progress should be aborted.
*
* Compare the current number of registered wakeup events with its preserved value from the past and return true if new wakeup events have been registered
* since the old value was stored.  Also return true if the current number of wakeup events being processed is different from zero.
*/

bool pm_wakeup_pending(void)
{
    unsigned long flags;
    bool ret = false;
 
    spin_lock_irqsave(&events_lock, flags);
    if (events_check_enabled) {
          unsigned int cnt, inpr;
          split_counters(&cnt, &inpr);
          ret = (cnt != saved_count || inpr > 0);
          events_check_enabled = !ret;
     }
     spin_unlock_irqrestore(&events_lock, flags);
     return ret;
}

如果註冊的wakeup events 數量有變化, 或是目前wakeup events 數大於0, 則 True
表示要終止 suspend, 即resume起來後再suspend動作
LOG參考如下:

[  285.370711] PM: suspend entry 2014-08-27 00:26:02.535471146 UTC   <=== 進入suspend動作
[  285.377034] PM: Syncing filesystems ... done.
[  285.423982] Freezing user space processes ... (elapsed 0.05 seconds) done.
[  285.489518] Freezing remaining freezable tasks ... (elapsed 0.02 seconds) done.
[  285.519359] Suspending console(s) (use no_console_suspend to debug)
[  285.636368] TTTTTT __device_suspend(),  Yes pm_wakeup_pending ..   <===我加的 message
[  285.636405] PM: Some devices failed to suspend!!
[  285.637872] [GPIO_KEY_WAKE] gpio:412, state:0
[  285.637919] [GPIO_KEY_WAKE] gpio:409, state:0
[  285.682804] hdmi_tx_hpd_on: HDMI HW version = 0x30000001
[  285.761673] PM: resume of devices complete after 125.242 msecs
[  285.792870] Restarting tasks ... done.
[  285.808806] PM: suspend exit 2014-08-27 00:26:02.973608228 UTC
[  285.814445] PM: suspend entry 2014-08-27 00:26:02.979247759 UTC   <=== 進入suspend動作
[  285.820297] PM: Syncing filesystems ... done.
[  285.833124] Freezing user space processes ... (elapsed 0.01 seconds) done.
[  285.858165] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
[  285.877691] Suspending console(s) (use no_console_suspend to debug)
[  285.916006] [bq2419x_charger_read_status] Read Reg08=0x00, Reg09=0x00, stat_gpio:1/1, pg_gpio:1/1, hiz: 0/0
[  285.970769] PM: suspend of devices complete after 84.786 msecs
[  285.971882] PM: late suspend of devices complete after 1.104 msecs
[  285.973659] PM: noirq suspend of devices complete after 1.766 msecs
[  285.973666] Disabling non-boot CPUs ...
[  285.973821] spmi_pmic_arb fc4cf000.qcom,spmi: int disable: invalid APID 256
[  285.973848] CPU0: msm_cpu_pm_enter_sleep mode:3

怎麼看是哪個wakeup_source造成的呢?

看一下程式碼就知道是這個變數 combined_event_count
(這個變數即是記錄註冊wakeup_sources數與目前in progress wakeup_sources數)
有兩個fuctions會去更動combined_event_count變數 :
1. wakeup_source_activate
2. wakeup_source_deactivate

加入以下程式碼去看, 在sysc完後再出現的wakeup source name
(因為events_check_enabled會在sysc後才被設True)

if(events_check_enabled)
    printk(KERN_ERR "TTTTTT wakeup_source_activate(), ws->name:%s\n", ws->name);

Example 如下:

/**
 * wakup_source_activate - Mark given wakeup source as active.
 * @ws: Wakeup source to handle.
 *
 * Update the @ws' statistics and, if @ws has just been activated, notify the PM
 * core of the event by incrementing the counter of of wakeup events being
 * processed.
 */
static void wakeup_source_activate(struct wakeup_source *ws)
{
	unsigned int cec;

	ws->active = true;
	ws->active_count++;
	ws->last_time = ktime_get();
	if (ws->autosleep_enabled)
		ws->start_prevent_time = ws->last_time;

	/* Increment the counter of events in progress. */
	cec = atomic_inc_return(&combined_event_count);
	
	if(events_check_enabled)
		printk(KERN_ERR "TTTTTT wakeup_source_activate(),  ws->name:%s\n", ws->name);

	trace_wakeup_source_activate(ws->name, cec);
}

再一Example:

/**
 * wakup_source_deactivate - Mark given wakeup source as inactive.
 * @ws: Wakeup source to handle.
 *
 * Update the @ws' statistics and notify the PM core that the wakeup source has
 * become inactive by decrementing the counter of wakeup events being processed
 * and incrementing the counter of registered wakeup events.
 */
static void wakeup_source_deactivate(struct wakeup_source *ws)
{
	unsigned int cnt, inpr, cec;
	ktime_t duration;
	ktime_t now;

	ws->relax_count++;
	/*
	 * __pm_relax() may be called directly or from a timer function.
	 * If it is called directly right after the timer function has been
	 * started, but before the timer function calls __pm_relax(), it is
	 * possible that __pm_stay_awake() will be called in the meantime and
	 * will set ws->active.  Then, ws->active may be cleared immediately
	 * by the __pm_relax() called from the timer function, but in such a
	 * case ws->relax_count will be different from ws->active_count.
	 */
	if (ws->relax_count != ws->active_count) {
		ws->relax_count--;
		return;
	}

	ws->active = false;

	now = ktime_get();
	duration = ktime_sub(now, ws->last_time);
	ws->total_time = ktime_add(ws->total_time, duration);
	if (ktime_to_ns(duration) > ktime_to_ns(ws->max_time))
		ws->max_time = duration;

	ws->last_time = now;
	del_timer(&ws->timer);
	ws->timer_expires = 0;

	if (ws->autosleep_enabled)
		update_prevent_sleep_time(ws, now);

	/*
	 * Increment the counter of registered wakeup events and decrement the
	 * couter of wakeup events in progress simultaneously.
	 */
	cec = atomic_add_return(MAX_IN_PROGRESS, &combined_event_count);
	trace_wakeup_source_deactivate(ws->name, cec);

	if(events_check_enabled)
		printk(KERN_ERR "TTTTTT wakeup_source_deactivate(),  ws->name:%s\n", ws->name);

	split_counters(&cnt, &inpr);
	if (!inpr && waitqueue_active(&wakeup_count_wait_queue))
		wake_up(&wakeup_count_wait_queue);
}

我的測試結果找出 event1-1202

<6>[  413.371801] Suspending console(s) (use no_console_suspend to debug)
<3>[  413.412673] TTTTTT wakeup_source_activate(),  ws->name:event1-1202
<3>[  413.454422] TTTTTT __device_suspend(),  Yes pm_wakeup_pending ..
<3>[  413.454430] PM: Some devices failed to suspend
<6>[  413.802075] PM: resume of devices complete after 347.632 msecs
<6>[  413.825610] Restarting tasks ... done.
<6>[  413.839963] PM: suspend exit 1970-01-02 00:08:03.900456038 UTC
<6>[  413.845279] PM: suspend entry 1970-01-02 00:08:03.905786559 UTC
<6>[  413.851261] PM: Syncing filesystems ... done.
<6>[  413.864707] Freezing user space processes ... (elapsed 0.02 seconds) done.
<6>[  413.891142] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.

#adb shell cat /sys/kernel/debug/wakeup_sources

 name                           active_count    event_count     wakeup_count    expire_count    active_since    total_time      max_time        last_change     prevent_suspend_time
ipc000000c7_sensors.qcom 0 0 0 0 0 0 0 650757 0
ipc000000c6_sensors.qcom 20 20 0 0 0 1 0 652384 0
ipc000000c5_sensors.qcom 0 0 0 0 0 0 0 650726 0
ipc000000c4_sensors.qcom 1 1 0 0 0 5 5 650732 0
rmt_storage_-1223766296 1 1 0 0 0 147 147 101285 0
PowerManagerService.Broadcasts 14 14 0 0 0 4579 573 651072 946
ipc000000ab_Thread-40 8 8 0 0 0 0 0 427711 0
ipc000000aa_Thread-40 1 1 0 0 0 0 0 16770 0
ipc000000a7_Thread-33 8 8 0 0 0 1 0 427711 0
ipc000000a6_Thread-33 1 1 0 0 0 0 0 16593 0
ipc000000a5_Thread-33 0 0 0 0 0 0 0 16509 0
ipc000000a2_Loc_hal_worker 8 8 0 0 0 0 0 427711 0
ipc000000a1_Loc_hal_worker 34 44 0 0 0 3 1 650803 0
ipc000000a0_Loc_hal_worker 0 0 0 0 0 0 0 16172 0
PowerManagerService.WakeLocks 42 42 0 0 0 48679 35780 651106 34599
event4-1202 15 15 0 0 0 952 327 414204 952
event0-1202 27 27 0 0 0 1789 397 414204 1785
event1-1202 89 99 16 0 0 3259 425 416181 3247
event2-1202 10 10 0 0 0 1784 396 414204 1784
event3-1202 12 12 0 0 0 121 91 414450 100
event5-1202 15 15 0 0 0 949 327 414204 949
event6-1202 0 0 0 0 0 0 0 15297 0
KeyEvents 162 162 0 0 0 303 141 646073 104
PowerManagerService.Display 8 8 0 0 1842 65335 13986 650571 186
ipc0000008d_sensors.qcom 8 8 0 0 0 0 0 427711 0
ipc0000008c_sensors.qcom 15 15 0 0 0 1 0 650757 0
ipc0000008b_sensors.qcom 8 8 0 0 0 0 0 427711 0
ipc0000008a_sensors.qcom 0 0 0 0 0 0 0 13073 0
qcril 51 51 0 0 0 542 55 651112 151
ipc00000087_thermal-engine 8 8 0 0 0 0 0 427711 0
ipc00000086_thermal-engine 3 3 0 0 0 0 0 12704 0
ipc00000085_thermal-engine 8 8 0 0 0 0 0 427711 0
ipc00000084_thermal-engine 2 2 0 0 0 0 0 12704 0
qmuxd_port_wl_7 21 21 0 0 0 0 0 16728 0
smdcntl7 21 37 0 0 0 1 0 16728 0
qmuxd_port_wl_6 21 21 0 0 0 0 0 16727 0
smdcntl6 21 34 0 0 0 1 0 16727 0
qmuxd_port_wl_5 21 21 0 0 0 0 0 16726 0
smdcntl5 21 35 0 0 0 1 0 16726 0
qmuxd_port_wl_4 21 21 0 0 0 0 0 16725 0
smdcntl4 21 33 0 0 0 1 0 16725 0
qmuxd_port_wl_3 21 21 0 0 0 0 0 16723 0
smdcntl3 21 33 0 0 0 1 0 16722 0
qmuxd_port_wl_2 21 21 0 0 0 0 0 16720 0
smdcntl2 21 34 0 0 0 1 0 16720 0
qmuxd_port_wl_1 64 64 0 0 0 8 1 651102 6
smdcntl1 57 94 0 0 0 8 0 651101 5
ipc00000083_time_daemon 8 8 0 0 0 0 0 427711 0
ipc00000082_time_daemon 1 1 0 0 0 0 0 11697 0
qmuxd_port_wl_0 300 300 0 0 0 25 0 651110 5
ipc0000003b_sensors.qcom 11 11 0 0 0 21 21 427711 0
ipc0000003a_sensors.qcom 0 0 0 0 0 0 0 11030 0
ipc00000039_sensors.qcom 11 11 0 0 0 3 2 427711 0
ipc00000038_sensors.qcom 1 1 0 0 0 0 0 101033 0
ipc00000037_sensors.qcom 11 11 0 0 0 2 2 427711 0
ipc00000036_sensors.qcom 1 1 0 0 0 0 0 11036 0
ipc00000035_sensors.qcom 12 12 0 0 0 0 0 427711 0
ipc00000034_sensors.qcom 0 0 0 0 0 0 0 11029 0
ipc00000033_sensors.qcom 13 13 0 0 0 0 0 427711 0
ipc00000032_sensors.qcom 0 0 0 0 0 0 0 11028 0
ipc00000031_sensors.qcom 14 14 0 0 0 0 0 427711 0
ipc00000030_sensors.qcom 0 0 0 0 0 0 0 11028 0
ipc0000002f_sensors.qcom 15 15 0 0 0 0 0 427711 0
ipc0000002e_sensors.qcom 0 0 0 0 0 0 0 11027 0
ipc0000002d_sensors.qcom 16 16 0 0 0 0 0 427711 0
ipc0000002c_sensors.qcom 0 0 0 0 0 0 0 11027 0
ipc0000002b_sensors.qcom 17 17 0 0 0 0 0 427711 0
ipc0000002a_sensors.qcom 0 0 0 0 0 0 0 11027 0
ipc00000029_sensors.qcom 18 18 0 0 0 1 0 427711 0
ipc00000028_sensors.qcom 0 0 0 0 0 0 0 11026 0
ipc00000027_sensors.qcom 19 19 0 0 0 0 0 427711 0
ipc00000026_sensors.qcom 0 0 0 0 0 0 0 11026 0
ipc00000025_sensors.qcom 20 20 0 0 0 1 0 427710 0
ipc00000024_sensors.qcom 0 0 0 0 0 0 0 11025 0
ipc00000023_sensors.qcom 20 20 0 0 0 0 0 427710 0
ipc00000022_sensors.qcom 9 9 0 0 0 0 0 11025 0
DIAG_DCI_WS 0 0 0 0 0 0 0 10916 0
DIAG_DCI_CMD_WS 0 0 0 0 0 0 0 10916 0
ipc0000001f_sensors.qcom 53 53 0 0 0 1 0 427710 0
ipc0000001e_sensors.qcom 6 6 0 0 0 0 0 11021 0
ipc0000001d_sensors.qcom 0 0 0 0 0 0 0 10855 0
ipc0000001a_sensors.qcom 54 54 0 0 0 20 17 427710 0
ipc00000019_sensors.qcom 15 15 0 0 0 1 0 650726 0
rmt_storage_-1223765448 2 2 0 0 0 28 28 10842 0
ipc00000018_ims_rtp_daemon 54 57 0 0 0 6 2 427710 0
ipc00000017_ims_rtp_daemon 0 0 0 0 0 0 0 10759 0
ipc_rtr_smd_ipcrtr 69 80 0 0 0 2 0 650803 0
radio-interface 11 28 0 0 0 15294 4076 652093 1000
qcril_pre_client_init 1 1 0 0 0 3037 3037 12739 0
ipc00000016_rmt_storage 54 63 0 0 0 1184 1178 427710 0
ipc00000015_rmt_storage 9 9 0 0 0 0 0 101137 0
ipc00000014_imsdatadaemon 54 63 0 0 0 1185 1180 427710 0
ipc00000013_imsdatadaemon 0 0 0 0 0 0 0 9376 0
ipc00000012_sensors.qcom 49 63 0 0 0 1353 1338 427710 0
ipc00000011_sensors.qcom 62 62 0 0 0 162 160 650756 0
ipc_rtr_wcnss_ipcrtr 2 3 0 0 0 2 2 9516 0
wcnss 0 0 0 0 0 0 0 8650 0
ipc00000010_time_daemon 0 0 0 0 0 0 0 8570 0
ipc0000000f_time_daemon 56 63 0 0 0 8 2 427710 0
ipc0000000e_time_daemon 0 0 0 0 0 0 0 8570 0
smdcntl0 289 392 0 0 0 41 4 651110 5
ipc0000000d_thermal-engine 63 63 0 0 0 1 0 427710 0
ipc0000000c_thermal-engine 0 0 0 0 0 0 0 8540 0
ipc00000009_thermal-engine 59 63 0 0 0 3 1 427710 0
ipc00000008_thermal-engine 0 0 0 0 0 0 0 8536 0
ipc00000007_thermal-engine 0 0 0 0 0 0 0 8535 0
ipc00000004_rfs_access 56 63 0 0 0 1187 1177 427710 0
ipc00000003_rfs_access 0 0 0 0 0 0 0 8483 0
taiko-slim-pgd 0 0 0 0 0 0 0 8280 0
ipc00000001_kworker/0:3 7 7 0 0 0 0 0 270041 0
ipc_rtr_q6_ipcrtr 1038 1051 0 0 0 38 1 652384 0
gpio_keys.81 0 0 0 0 0 0 0 5846 0
bam_dmux_wakelock 2 2 0 0 0 4001 2001 15602 0
coresight-etm 0 0 0 0 0 0 0 5547 0
coresight-etm 0 0 0 0 0 0 0 5536 0
coresight-etm 0 0 0 0 0 0 0 5526 0
coresight-etm 0 0 0 0 0 0 0 5516 0
qpnp-power-on-ec947800 0 0 0 0 0 0 0 5307 0
mmc0_detect 1 1 0 1 0 496 496 5470 0
msm_smd_Tx 0 0 0 0 0 0 0 4654 0
msm_smd_Rx 0 0 0 0 0 0 0 4654 0
qpnp-iadc-ec948a00 2 2 0 0 0 19 9 605930 9
qpnp-vadc-ec948800 51 51 0 0 0 292 21 651367 69
power-supply 15 15 0 0 0 24 4 651364 10
bq2419x_eoc 5 17 0 0 2258 626559 257916 650156 562347
bq2419x_usb 8 9 0 8 0 8525 1552 651580 1044
power-supply 2 2 0 0 0 0 0 5020 0
bq27529_fw_update 0 0 0 0 0 0 0 4172 0
video2 0 0 0 0 0 0 0 4067 0
video1 0 0 0 0 0 0 0 4017 0
qpnp-rtc-ec948600 0 0 0 0 0 0 0 3736 0
alarm 19 19 1 0 0 765 474 649939 760
alarm_rtc 3 3 0 0 0 6 6 13894 0
msm_dwc3 8 8 0 0 2144 628464 259752 650271 562561
power-supply 44 97 0 0 0 448 41 651368 157
diag_nrt_wcnss_read 0 0 0 0 0 0 0 2660 0
diag_nrt_lpass_read 0 0 0 0 0 0 0 2660 0
diag_nrt_modem_read 0 0 0 0 0 0 0 2660 0
msm_serial_hs_dma 2 2 0 0 0 8 5 8396 0
msm_serial_hs_rx 1 8 0 1 0 499 499 8890 0
qmi2 0 0 0 0 0 0 0 290 0
qmi1 0 0 0 0 0 0 0 290 0
qmi0 0 0 0 0 0 0 0 290 0
ssr(venus) 0 0 0 0 0 0 0 285 0
pil-venus 0 0 0 0 0 0 0 285 0
ssr(wcnss) 0 0 0 0 0 0 0 284 0
pil-wcnss 1 1 0 0 0 592 592 9513 0
ssr(modem) 0 0 0 0 0 0 0 282 0
pil-modem 0 0 0 0 0 0 0 282 0
pil-mba 1 1 0 0 0 2151 2151 10744 0
ssr(adsp) 0 0 0 0 0 0 0 281 0
pil-adsp 1 1 0 0 0 182 182 8174 0
smsm_snapshot 11 11 0 0 0 27 26 15602 0
autosleep 15 15 0 0 0 1 1 650724 1



發表迴響