Hi
I have seen an issue in autosleep suspend sequence. While validating the autosleep in the android setup using POWER input event.
Android version: KitKat
Linux kernel Version: 3.10
Issue description:
1. Android attempts autosleep with POWER input event.
2. In autosleep sequence at the time of suspend, suspend_prepare will call pm notifier function “mmc_pm_notify” in PM_SUSPEND_PREPARE mode.
3. With mmc pm notifier call mmc card is removed.
4. Android user space demon has received the card removed events and acquires the NETLINK wakeup source for cleanup.
5. In the same suspend_prepare sequence “try_to_freeze_tasks” function is called from freeze_processes function.
6. try_to_freeze_tasks function has aborted because of pending wakeup source NETLINK and returns error to suspend_prepare call.
7. With above error suspend_prepare calls mmc pm notifier function in PM_POST_SUSPEND mode.
8. With mmc pm notifier call mmc card is detected back.
9. Android user space demon has received the card detected events and releases the NETLINK wakeup source.
10. Android re-attempts the autosleep and repeats same sequence of 2 to 9. This goes infinite.
try_to_freeze_tasks:
In this function all the tasks are going to freeze in while loop before end_time and also checks the pm_wakeup_pending condition.
The highlighted part in the below code is checks for the pending wakeup sources. In my issue NETLINK is the pending wakeup source.
If I move the highlighted code block to outside of the loop then I did not seen any pending wakeup sources, because NETLINK wakeup source is released by the time all the tasks are freeze.
At the time of second iteration of the loop the NETLINK wakeup source has released, If I did not break the loop with pm_wakeup_pending condition check in the first iteration. This is verified in my issue scenario.
But moving the pm_wakeup_pending condition check outside of the loop may not the right solution;
Because there may be scenarios like wakeup sources are based on devices which need pm notifier call with PM_POST_SUSPEND.
Debug log is attached with this mail.
Could you please suggest me the right solution?
while (true) {
todo = 0;
read_lock(&tasklist_lock);
do_each_thread(g, p) {
if (p == current || !freeze_task(p))
continue;
if (!freezer_should_skip(p))
todo++;
} while_each_thread(g, p);
read_unlock(&tasklist_lock);
if (!user_only) {
wq_busy = freeze_workqueues_busy();
todo += wq_busy;
}
if (!todo || time_after(jiffies, end_time))
break;
if (pm_wakeup_pending()) { “This check is true in my case because of NETLINK wakeup source is active”
#ifdef CONFIG_PM_SLEEP
pm_get_active_wakeup_sources(suspend_abort,
MAX_SUSPEND_ABORT_LEN);
log_suspend_abort_reason(suspend_abort);
#endif
wakeup = true;
break;
}
/*
* We need to retry, but first give the freezing tasks some
* time to enter the refrigerator. Start with an initial
* 1 ms sleep followed by exponential backoff until 8 ms.
*/
usleep_range(sleep_usecs / 2, sleep_usecs);
if (sleep_usecs < 8 * USEC_PER_MSEC)
sleep_usecs *= 2;
}
Srinath Babu Mannam
[ 310.280000] PM: suspend entry 2015-07-30 14:46:20.713275043 UTC [ 310.280000] PM: Syncing filesystems ... done. [ 310.310000] mmc0: card 0001 removed [ 310.330000] Freezing user space processes ... task todo is debuggerd [ 310.330000] task todo is sdcard [ 310.340000] task todo is sdcard [ 310.340000] task todo is sdcard [ 310.340000] task todo is sh [ 310.350000] task todo is adbd [ 310.350000] task todo is FileObserver [ 310.350000] task todo is AlarmManager [ 310.360000] task todo is EthMonitor [ 310.360000] task todo is Thread-55 [ 310.360000] task todo is d.process.media [ 310.370000] task todo is sdcard [ 310.370000] task todo is sdcard [ 310.370000] task todo is sdcard [ 310.380000] active wakeup source: NETLINK [ 310.380000] all todos = 14 [ 310.380000] [ 310.390000] Freezing of tasks aborted after 0.051 seconds [ 310.390000] Restarting tasks ... done. [ 310.400000] PM: suspend exit 2015-07-30 14:46:20.833449009 UTC [ 310.480000] mmc0: new high speed SDHC card at address 0001 [ 310.500000] mmcblk0: mmc0:0001 00000 7.46 GiB [ 310.500000] mmcblk0: p1 [ 311.000000] PM: suspend entry 2015-07-30 14:46:21.432651106 UTC [ 311.000000] PM: Syncing filesystems ... done. [ 311.010000] mmc0: card 0001 removed [ 311.020000] Freezing user space processes ... task todo is debuggerd [ 311.020000] task todo is sdcard [ 311.030000] task todo is sdcard [ 311.030000] task todo is sdcard [ 311.030000] task todo is sh [ 311.040000] task todo is adbd [ 311.040000] task todo is FileObserver [ 311.040000] task todo is AlarmManager [ 311.050000] task todo is EthMonitor [ 311.050000] task todo is Thread-55 [ 311.050000] task todo is sdcard [ 311.060000] task todo is sdcard [ 311.060000] task todo is sdcard [ 311.060000] last active wakeup source: eventpoll [ 311.070000] all todos = 13 [ 311.070000] [ 311.070000] Freezing of tasks aborted after 0.048 seconds [ 311.080000] Restarting tasks ... done. [ 311.080000] PM: suspend exit 2015-07-30 14:46:21.519629051 UTC [ 311.160000] mmc0: new high speed SDHC card at address 0001 [ 311.170000] mmcblk0: mmc0:0001 00000 7.46 GiB [ 311.180000] mmcblk0: p1 [ 311.680000] PM: suspend entry 2015-07-30 14:46:22.112656935 UTC [ 311.680000] PM: Syncing filesystems ... done. [ 311.690000] mmc0: card 0001 removed [ 311.700000] Freezing user space processes ... task todo is debuggerd [ 311.700000] task todo is sdcard [ 311.710000] task todo is sdcard [ 311.710000] task todo is sdcard [ 311.710000] task todo is sh [ 311.720000] task todo is adbd [ 311.720000] task todo is FileObserver [ 311.720000] task todo is AlarmManager [ 311.730000] task todo is EthMonitor [ 311.730000] task todo is Thread-55 [ 311.730000] last active wakeup source: eventpoll [ 311.740000] all todos = 10 [ 311.740000] [ 311.740000] Freezing of tasks aborted after 0.039 seconds [ 311.750000] Restarting tasks ... done. [ 311.750000] PM: suspend exit 2015-07-30 14:46:22.188678607 UTC [ 311.830000] mmc0: new high speed SDHC card at address 0001 [ 311.840000] mmcblk0: mmc0:0001 00000 7.46 GiB [ 311.850000] mmcblk0: p1 [ 312.350000] PM: suspend entry 2015-07-30 14:46:22.782687673 UTC [ 312.350000] PM: Syncing filesystems ... done. [ 312.370000] mmc0: card 0001 removed [ 312.830000] Freezing user space processes ... task todo is debuggerd [ 312.830000] task todo is sdcard [ 312.840000] task todo is sdcard [ 312.840000] task todo is sdcard [ 312.840000] task todo is sh [ 312.840000] task todo is adbd [ 312.850000] task todo is FileObserver [ 312.850000] task todo is AlarmManager [ 312.850000] task todo is EthMonitor [ 312.860000] task todo is Thread-55 [ 312.860000] task todo is Compiler [ 312.860000] task todo is fsck_msdos [ 312.870000] last active wakeup source: eventpoll [ 312.870000] all todos = 12 [ 312.880000] [ 312.880000] Freezing of tasks aborted after 0.045 seconds [ 312.880000] Restarting tasks ... done. [ 312.910000] PM: suspend exit 2015-07-30 14:46:23.343484203 UTC [ 312.990000] mmc0: new high speed SDHC card at address 0001 [ 313.010000] mmcblk0: mmc0:0001 00000 7.46 GiB [ 313.010000] mmcblk0: p1 [ 313.540000] PM: suspend entry 2015-07-30 14:46:23.972662897 UTC [ 313.540000] PM: Syncing filesystems ... done. [ 313.550000] mmc0: card 0001 removed [ 313.870000] Freezing user space processes ... task todo is debuggerd [ 313.870000] task todo is sdcard [ 313.880000] task todo is sdcard [ 313.880000] task todo is sdcard [ 313.880000] task todo is sh [ 313.890000] task todo is adbd [ 313.890000] task todo is FileObserver [ 313.890000] task todo is AlarmManager [ 313.900000] task todo is EthMonitor [ 313.900000] task todo is Thread-55 [ 313.900000] task todo is fsck_msdos [ 313.910000] active wakeup source: NETLINK [ 313.910000] all todos = 11 [ 313.910000] [ 313.910000] Freezing of tasks aborted after 0.041 seconds [ 313.920000] Restarting tasks ... done. [ 313.940000] PM: suspend exit 2015-07-30 14:46:24.373486796 UTC [ 314.020000] mmc0: new high speed SDHC card at address 0001 [ 314.040000] mmcblk0: mmc0:0001 00000 7.46 GiB [ 314.040000] mmcblk0: p1 [ 314.550000] PM: suspend entry 2015-07-30 14:46:24.982693191 UTC [ 314.550000] PM: Syncing filesystems ... done. [ 314.560000] mmc0: card 0001 removed [ 314.930000] Freezing user space processes ... task todo is debuggerd [ 314.930000] task todo is sdcard [ 314.940000] task todo is sdcard [ 314.940000] task todo is sdcard [ 314.940000] task todo is sh [ 314.950000] task todo is adbd [ 314.950000] task todo is system_server [ 314.950000] task todo is FileObserver [ 314.960000] task todo is AlarmManager [ 314.960000] task todo is EthMonitor [ 314.960000] task todo is Thread-55 [ 314.970000] task todo is ndroid.systemui [ 314.970000] task todo is fsck_msdos [ 314.970000] active wakeup source: NETLINK [ 314.980000] all todos = 13 [ 314.980000] [ 314.980000] Freezing of tasks aborted after 0.049 seconds [ 314.990000] Restarting tasks ... done. [ 315.010000] PM: suspend exit 2015-07-30 14:46:25.443488703 UTC [ 315.100000] mmc0: new high speed SDHC card at address 0001 [ 315.120000] mmcblk0: mmc0:0001 00000 7.46 GiB [ 315.120000] mmcblk0: p1 [ 315.630000] PM: suspend entry 2015-07-30 14:46:26.062660377 UTC [ 315.630000] PM: Syncing filesystems ... done. [ 315.640000] mmc0: card 0001 removed [ 316.020000] Freezing user space processes ... task todo is debuggerd [ 316.020000] task todo is sdcard [ 316.030000] task todo is sdcard [ 316.030000] task todo is sdcard [ 316.030000] task todo is sh [ 316.040000] task todo is adbd [ 316.040000] task todo is GC [ 316.040000] task todo is FileObserver [ 316.050000] task todo is AlarmManager [ 316.050000] task todo is EthMonitor [ 316.050000] task todo is Thread-55 [ 316.060000] task todo is fsck_msdos [ 316.060000] active wakeup source: NETLINK [ 316.060000] all todos = 12 [ 316.070000] [ 316.070000] Freezing of tasks aborted after 0.044 seconds [ 316.070000] Restarting tasks ... done. [ 316.100000] PM: suspend exit 2015-07-30 14:46:26.533553425 UTC [ 316.190000] mmc0: new high speed SDHC card at address 0001 [ 316.220000] mmcblk0: mmc0:0001 00000 7.46 GiB [ 316.220000] mmcblk0: p1 [ 316.720000] PM: suspend entry 2015-07-30 14:46:27.152661436 UTC [ 316.720000] PM: Syncing filesystems ... done. [ 316.730000] mmc0: card 0001 removed [ 317.120000] Freezing user space processes ... task todo is netd [ 317.120000] task todo is debuggerd [ 317.130000] task todo is sdcard [ 317.130000] task todo is sdcard [ 317.130000] task todo is sdcard [ 317.140000] task todo is sh [ 317.140000] task todo is adbd [ 317.140000] task todo is system_server [ 317.150000] task todo is FileObserver [ 317.150000] task todo is AlarmManager [ 317.150000] task todo is EthMonitor [ 317.160000] task todo is Thread-55 [ 317.160000] task todo is ndroid.systemui [ 317.160000] task todo is fsck_msdos [ 317.170000] active wakeup source: NETLINK [ 317.170000] all todos = 14 [ 317.170000] [ 317.180000] Freezing of tasks aborted after 0.052 seconds [ 317.180000] Restarting tasks ... done. [ 317.200000] PM: suspend exit 2015-07-30 14:46:27.633486256 UTC [ 317.280000] mmc0: new high speed SDHC card at address 0001 [ 317.300000] mmcblk0: mmc0:0001 00000 7.46 GiB [ 317.300000] mmcblk0: p1 [ 317.810000] PM: suspend entry 2015-07-30 14:46:28.242658742 UTC [ 317.810000] PM: Syncing filesystems ... done. [ 317.820000] mmc0: card 0001 removed [ 318.180000] Freezing user space processes ... task todo is debuggerd [ 318.180000] task todo is sdcard [ 318.190000] task todo is sdcard [ 318.190000] task todo is sdcard [ 318.190000] task todo is sh [ 318.200000] task todo is adbd [ 318.200000] task todo is FileObserver [ 318.200000] task todo is AlarmManager [ 318.210000] task todo is VoldConnector [ 318.210000] task todo is EthMonitor [ 318.210000] task todo is Thread-55 [ 318.220000] task todo is fsck_msdos [ 318.220000] active wakeup source: NETLINK [ 318.220000] all todos = 12 [ 318.230000] [ 318.230000] Freezing of tasks aborted after 0.045 seconds [ 318.230000] Restarting tasks ... done. [ 318.260000] PM: suspend exit 2015-07-30 14:46:28.693487481 UTC [ 318.350000] mmc0: new high speed SDHC card at address 0001 [ 318.370000] mmcblk0: mmc0:0001 00000 7.46 GiB [ 318.370000] mmcblk0: p1 [ 318.880000] PM: suspend entry 2015-07-30 14:46:29.312658283 UTC [ 318.880000] PM: Syncing filesystems ... done. [ 318.890000] mmc0: card 0001 removed [ 319.250000] Freezing user space processes ... task todo is debuggerd [ 319.250000] task todo is sdcard [ 319.260000] task todo is sdcard [ 319.260000] task todo is sdcard [ 319.260000] task todo is sh [ 319.270000] task todo is adbd [ 319.270000] task todo is FileObserver [ 319.270000] task todo is AlarmManager [ 319.280000] task todo is VoldConnector [ 319.280000] task todo is EthMonitor [ 319.280000] task todo is Thread-55 [ 319.290000] task todo is fsck_msdos [ 319.290000] active wakeup source: NETLINK [ 319.290000] all todos = 12 [ 319.300000] [ 319.300000] Freezing of tasks aborted after 0.045 seconds [ 319.300000] Restarting tasks ... done. [ 319.320000] PM: suspend exit 2015-07-30 14:46:29.753489384 UTC [ 319.410000] mmc0: new high speed SDHC card at address 0001 [ 319.430000] mmcblk0: mmc0:0001 00000 7.46 GiB [ 319.430000] mmcblk0: p1
