灭屏时间内，部分时间段，AP侧进不了待机流程的分析方法(standby,suspend)

platform:msm8909, android 8.0
案例: 国内插移动卡，关闭数据，连接翻墙的wifi，灭屏待机，灭屏时间内，部分时间段，AP侧进不了待机流程。

通过上图我们发现，总共灭屏时间段有11分钟零7秒，中间有大约（6100-3600）/10 = 250秒的时间，AP侧进不了待机流程，这250秒的时间，待机底电流基本维持在30mA以上。
整个灭屏时间段，抓取日志的过程:
1、PowerManagerService持锁导致的AP侧进不了待机流程，需要将PowerManagerService的debug code打开后复测问题，抓取log。 

--- a/services/core/java/com/android/server/power/PowerManagerService.java
+++ b/services/core/java/com/android/server/power/PowerManagerService.java
@@ -88,7 +88,7 @@ public final class PowerManagerService extends SystemService
implements Watchdog.Monitor {
private static final String TAG = "PowerManagerService";

- private static final boolean DEBUG = false;
+ private static final boolean DEBUG = true;
}

这里按照上面的方法打开debug code，重新编译services.jar以后，重启机器生效。
2、亮屏状态下执行如下命令:
adb root 
adb remount 
adb shell
3、
如果当前的版本集成了离线日志，通过离线日志抓取kernel层日志和framework层的logcat日志，否则的话，则通过如下方法抓取:
cat /proc/kmsg > kmsg.txt &
logcat -v time > logcat.txt &
具体请查阅"不通过uart的方式，抓取kernel层的待机日志(framework，log, off, qcom，串口)"一文。
4、while true; do sleep 10 && cat /sys/kernel/debug/wakeup_sources >> /data/wakeup_source.log && echo "+++++++++++++++++++++++++++" >> /data/wakeup_source.log; done &
5、拔掉USB，灭屏待机复现问题； 
6、导出kernel层日志和framework层的logcat日志
7、adb pull /data/wakeup_source.log .

打开kernel层的日志(或者kmsg.txt)，我们可以找到如下关键字:

PM: suspend exit 2018-07-20 08:32:10.739922784 UTC //这个是UTC时间，转换成北京(东八区)时间是在UTC时间上再加8个小时，即08:32:10 + 8hours = 16:32:10。
PM: suspend entry 2018-07-20 08:36:24.747980291 UTC //这个是UTC时间，转换成北京(东八区)时间是在UTC时间上再加8个小时，即08:36:24 + 8hours = 16:36:24。

说明AP侧在上次被唤醒以后，确实有将近250秒(确切来说，是254秒)的时间没有进入待机流程。

通过查看wakeup_source.log，如下：

可以看出PowerManagerService.WakeLocks持锁导致有4分钟(确切来说，是243.969秒)没有走待机流程，看active_since列(倒数第五个)
PowerManagerService.WakeLocks是上层应用持锁，具体是哪个应用持锁，需要在framework层日志(或者logcat.txt)里面搜索关键字"acquireWakeLockInternal"，"releaseWakeLockInternal"，如下:

07-20 16:26:07.787 I/PowerManagerService( 691): Going to sleep due to power button (uid 1000)...
07-20 16:26:08.278 I/PowerManagerService( 691): Dozing...
... ... ...
07-20 16:37:23.473 I/PowerManagerService( 691): Waking up from dozing (uid=1000 reason=android.policy:POWER)...

可以看出系统在时间16:26:07通过power键灭屏，在时间16:37:23通过power键亮屏。

上面讲到，通过kernel层日志(或者kmsg.txt)里面，我们可以看到AP侧在上次被唤醒以后，确实有将近250秒(确切来说，是254秒)的时间没有进入待机流程。北京时间分别是16:32:10 和 16:36:24，framework层日志(或者logcat.txt)里面，在这段时间内(16:32:10至16:36:24)，搜索关键字"acquireWakeLockInternal"，"releaseWakeLockInternal"。
可以看出是com.google.android.gms在不停的持锁和释放锁,锁的类型有:net_scheduler，CMWakeLock。

... ...
07-20 16:33:04.105 D/PowerManagerService( 691): acquireWakeLockInternal: lock=139231586, flags=0x1, tag="*net_scheduler*", ws=WorkSource{10019 com.google.android.gms}, uid=10019, pid=3892
07-20 16:33:11.303 D/PowerManagerService( 691): acquireWakeLockInternal: lock=139231586, flags=0x1, tag="*net_scheduler*", ws=WorkSource{10019 com.google.android.gms}, uid=10019, pid=3892
07-20 16:33:11.388 D/PowerManagerService( 691): acquireWakeLockInternal: lock=233322604, flags=0x1, tag="CMWakeLock", ws=WorkSource{10019 com.google.android.gms}, uid=10019, pid=3892
07-20 16:33:14.736 D/PowerManagerService( 691): acquireWakeLockInternal: lock=187793027, flags=0x1, tag="*net_scheduler*", ws=WorkSource{10019 com.google.android.gms}, uid=10019, pid=3892
07-20 16:34:14.922 D/PowerManagerService( 691): acquireWakeLockInternal: lock=233322604, flags=0x1, tag="CMWakeLock", ws=WorkSource{10019 com.google.android.gms}, uid=10019, pid=3892

... ...
07-20 16:33:04.133 D/PowerManagerService( 691): releaseWakeLockInternal: lock=139231586 [*net_scheduler*], flags=0x0
07-20 16:33:14.587 D/PowerManagerService( 691): releaseWakeLockInternal: lock=107440414 [*net_scheduler*], flags=0x0
07-20 16:34:14.930 D/PowerManagerService( 691): releaseWakeLockInternal: lock=233322604 [CMWakeLock], flags=0x0
07-20 16:35:23.307 D/PowerManagerService( 691): releaseWakeLockInternal: lock=231053380 [*net_scheduler*], flags=0x0
07-20 16:36:24.743 D/PowerManagerService( 691): releaseWakeLockInternal: lock=187793027 [*net_scheduler*], flags=0x0

由此，针对上面这个案例，我们可以看出，在灭屏时间内，部分时间段(即:4分钟)，AP侧进不了待机流程的原因是com.google.android.gms在不停的持锁和释放锁导致的。
疑问: 既然com.google.android.gms在不停的持锁和释放锁，为什么AP侧不在这次释放锁到下次持锁的这段时间内，进入待机流程呢？
解答: AP侧是周期性的通过写/sys/power/state节点来进入待机流程的，因为这次释放锁到下次持锁的时间间隔很短，AP侧还没有周期性的到写/sys/power/state节点的时间，所以进不了待机流程。

备注:
1. kernel层日志，framework层的logcat日志，wakeup_source.log文件：
kmsg+logcat+wakeup_source.rar

请参考附件(kmsg+logcat+wakeup_source.rar)。
2. wakeup_source.log文件里面，PowerManagerService持锁的名字有多个,区别如下:
PowerManagerService.WakeLocks，是控制AP侧保持唤醒状态的。
PowerManagerService.Display，是亮屏锁，控持该锁时，屏幕会保持常亮的状态。
PowerManagerService.Broadcasts，是控制电源状态改变通知的锁。