先看一幅图,在待机过程中,有三个跃起,其中两个尖峰,一个10s宽度;尖峰对长待机电流影响不大,而10s宽度100mA的电流则对平均电流有影响。
首先查看kernel log; 由于在抓取时,通过按键点亮屏幕,因此在kernel log中寻找按键中断则可以确定时间区域;清理掉无关log之后,搜索"PM: suspend":
通过比对电流图,可见从1到2经历1min50s,从2到3经历70s,而从3到按键点亮屏幕,经历40s;
而中间2:49:11(UTC时间需加8小时转换为当前时间)有两次suspend entry为何不计算呢? 因为从log中可见 其没有真正进入suspend。MTK平台真正进入suspend的最后一行打印是[name:spm&][SPM] md_settle = 99, settle = 33; 也就是说这两次suspend被中止了。也就是说在2处,尝试了3次suspend才成功。
在询问MTK的时候,他们常常会告诉你是否是上层apk引起的唤醒,那么我们再根据tcpdump来看
显然在10:49:11的时候有过一次网络ack,但是仅此一次,而从10:45:28开始就没有数据传输了,因此后面的1/2/3都不能算作apk唤醒;同样通过main log,也能看到FwmarkServer只出现在10:45:27处,后面不再出现。
/system/netd/server/FwmarkServer.cpp
int FwmarkServer::processClient(SocketClient* client, int* socketFd){
...
if (netdEventListener != nullptr) {
char addrstr[INET6_ADDRSTRLEN];
char portstr[sizeof("65536")];
const int ret = getnameinfo((sockaddr*) &connectInfo.addr, sizeof(connectInfo.addr),
addrstr, sizeof(addrstr), portstr, sizeof(portstr),
NI_NUMERICHOST | NI_NUMERICSERV);
+ LOG(ERROR) << "FwmarkServer connect uid = " << client->getUid() << " addr = " << addrstr << ", port " << portstr;
接着继续看这个2处的10s宽度是什么造成的:
我们已经确定跃起的时间点10:49:11,那么寻找main log和system log中对应的时间点;
当然也可以直接寻找logcat中的时间点。
logcat -v threadtime -b kernel -b main -b system -b radio > a.log
main log中可以看到 打印很少,说明进入休眠后上层就没有活动了
在system log中我们只看到10:49:11处有log,前后都是断开的,直接间隔1min,与电流波形类似
这里有两个alarm,type 3是唤醒源;在AlarmManager log中,奇数次的type是能够影响电流的,而偶数次的type影响不大,比如type 0, type 2不会影响,而type 1, type 3则会影响;可见唤醒的是android这个进程。从PowerManagerService中也能看到一个持锁,但是这个持锁很快就释放了,因此怎么会有10s宽度的电流呢?这个1min50s之后的2处的唤醒时怎样形成的呢?我们已经确定时间了,是10:49:11,但是我们在上层log中发现的信息很有限,支撑不了10s的理由。那么继续在kernel中看。
我们从kernel log中,可以看到 md_settle的最后打印,说明是真正的休眠,那么向后一点看他的唤醒:[name:spm&][SPM] suspend wake up by R12_EINT_EVENT_B; 这个R12_EINT_EVENT_B是MTK自己定义的东西,表面是外部唤醒;那么kernel原生的唤醒标志是设么呢:pm_system_irq_wakeup: 170 triggered mt6358-irq,也是外部中断,是PMIC上的中断;我们可以看到pm_system_irq_wakeup的次数与md_settle的次数是一致的;
我们还看到这个唤醒后,后面尝试了3次休眠,前两次都是失败的;我们看一下失败的原因,他们都是没有能够真正的进入suspend,没有md_settle的打印;
第一次尝试suspend:
Abort: Pending Wakeup Sources: ccmni_md1
可见是modem侧的唤醒阻值了休眠;
第二次上市suspend:
PM: Last active Wakeup Source: bat_percent_notify_lock wakelock
suspend of devices aborted after 232.760 msecs
PM: Some devices failed to suspend, or early wake event detected
一些设备未能休眠成功,哪些设备呢?没说;又说或者是早期的一些wake 事件被检测到,哪些事件呢,又没有讲。也许通过log是可以分析出来的。
其实从这里我们可以去学习一下suspend过程,比如说这个pending wakeup, 比如说这个last active wakeup source.