拿到性能问题后,首先要做基本排查,
1. 确认是不是kernel perf 版本
2. 确认kernel debug flag
3. 检查config.zip是否有不该打开的debug feature
4. 打开performance mode之后是否有改善,如果有改善,建议和高通沟通一起优化。
打开方法如下:
adb root
adb shell setenforce 0
adb shell stop perfd
adb shell stop thermal-engine
adb shell 'echo performance > /sys/devices/system/cpu/cpu0/cpufreq/scaling_governor'
adb shell 'echo performance >/sys/devices/system/cpu/cpu4/cpufreq/scaling_governor'
如果以上配置check都没问题,
接下来继续看logcat
通过看Choreographer: Skipped, OpenGLRenderer: Davey! duration , Displayed这些关键词判断什么变卡顿,
变卡顿时,观察是否所有apk还是单个或者某些apk变卡顿,如果是单个apk卡顿,使用traceview 和systrace,kill命令还有profiler工具,进一步排查比较方便。
systrace主要看cpu schedule(包含frequency 和 线程调度),celling frequency, 对应进程的frame, vsync信号。
关于systrace 和 traceview 详细使用后续再更新。
kill -3 pid 命令可以抓取该进程当前状态下所有线程堆栈信息,即Dalvik Threads信息,以此来check 此进程下的线程是否存在死锁问题。
如果是所有apk变卡顿,就变成了系统性能问题,接下来主要讲分析系统卡顿问题的思路,
遇到整体性能下降的问题,
首先要排查下RAM剩余空间,方法有bugreport, dumpsys meminfo, cat /proc/meminfo, lowmemorykiller log, kswapd cpu占用
还有一个释放RAM的命令,echo 3 > /proc/sys/vm/drop_caches 反向确认是否是内存不足引起的卡顿。
其次, 排查下emmc的容量和读写IO速度,
排查emmc的容量,可以借助benchmark等工具跑分测试,如antutu。还有就是反向debug, 清理emmc空间后是否存在卡顿现象。
IO读写速度的排查,可以借助fio, AndroBench等工具去check, 还有就是dd命令,
dd if=/dev/zero of=./largefile bs=8K count=1024 //测试写的速度,包含了系统调用和IO
dd if=./largefile of=/dev/null bs=8k //测试读的速度,包含了系统调用和IO
还有就是TP的check, 可以使用adb shell input swipe 350 900 350 300 300 这指令去check。如果还是卡,说明跟TP无关。
排查完上面的硬件问题后,接下来就是重点部分了。
系统性能问题分 framework 和 kernel 2 层,
framework层的性能问题,主要依赖于android 自带的一些工具和手段,比如,systrace,traceview,android profiler.
kernel 层的性能问题,主要依赖于linux 一些调试工具和手段。比如top, strace, ftrace.
先来说说之前遇到一个整体性能变卡的问题。
对于这种问题,首先需要确认是上层的问题还是kernel层的问题。
判别的具体方法如下:
1. 使用adb shell stop, adb shell start命令判断 重启后是否还卡顿。
2. 使用一个简单的命令 用strace 对比正常机器是否所有系统调用变慢。
strace -c cat /sys/kernel/debug/tracing/tracing_on
strace -tt -T -v -f -p pid -o /sdcard/logname.log
3. 制作简单的循环脚本去执行chmod, cat, ls等命令,与正常机器做对比是否都变慢
如果确认上面几项都变慢,那么基本上可以判定kernel的syscall都变了。
那么在kernel syscall 大部分都变慢的情况下,现在试下来没有什么好的方法,只有通过自己写test case 去确认哪个系统调用变慢,需要结合抓取操作变慢的场景下ramdump分析源码里 code逻辑和变量值。如何写test case?
可以写一个daemon, 循环去执行ls, cat ,chmod等基本命令,跟正常的机器对比,确认出哪个命令差距较大。然后在对该命令做进一步排查
以chmod调用慢为例,首先需要编写一个daemon,也就是一个bin档可以循环去执行chmod, 然后编写一个ko, 去打印chmod源码流程里的每个函数的耗时,来确认哪个函数出了问题,再来看对应
函数可能发生的耗时操作。
ko文件的编写以及怎么结合linux deamon进程来追踪哪个syscall变慢,这个步骤的详细介绍,后续在更新。
当时查到user_path_at->security_path_chmod->security_inode_setattr 这几个函数耗时较长,最后返现跟selinux有关。
所以以selinux为例,
selinux 有这样一个机制,当系统调用去检查selinux policy的时候,首先会检查avc cache里面policy, 如果存在就直接使用avc cache里面的值,如果不存在就会从db重新读取到avc cache.
所以这个是跟性能关系很大,是可疑点。
同时也可以用cat /sys/fs/selinux/avc/cache_stats来查看,执行结果如下:
lookups hits misses allocations reclaims frees
1774786 1759569 15217 15604 14509 10688
2134509 2119175 15334 15934 15187 9169
1785290 1770881 14409 14687 14112 17670
1442715 1428358 14357 14978 14528 16211
407859 401975 5884 6009 6016 6408
318615 313979 4636 4668 4576 6008
244824 241135 3689 3783 3760 6642
221858 217765 4093 4252 4288 6614
其中 reclaims 这一项每次增加很多说明就有问题,因为reclaim操作是比较耗时的, misses每次增加很多,也是有影响,但是耗时没reclaim那么严重。
来看下reclaim为什么耗时,
static inline int avc_reclaim_node(void)
{
struct avc_node *node;
int hvalue, try, ecx;
unsigned long flags;
struct hlist_head *head;
spinlock_t *lock;
for (try = 0, ecx = 0; try < AVC_CACHE_SLOTS; try++) {
hvalue = atomic_inc_return(&avc_cache.lru_hint) & (AVC_CACHE_SLOTS - 1);
head = &avc_cache.slots[hvalue];
lock = &avc_cache.slots_lock[hvalue];
if (!spin_trylock_irqsave(lock, flags))
continue;
rcu_read_lock();
hlist_for_each_entry(node, head, list) {
avc_node_delete(node);
avc_cache_stats_incr(reclaims);
ecx++;
if (ecx >= AVC_CACHE_RECLAIM) {
rcu_read_unlock();
spin_unlock_irqrestore(lock, flags);
goto out;
}
}
rcu_read_unlock();
spin_unlock_irqrestore(lock, flags);
}
out:
return ecx;
}
从relaim的源码可以看到,里面有一个循环体,循环次数是AVC_CACHE_SLOTS,源码定义的是512,所以需要循环512次大大增加了cpu的开销。
再来看relaim具体做的什么,avc_reclaim_node函数会去全部清掉所有avc nodes(512个)。
来看下调用这个avc api(avc_update_node)的大致流程,
流程1:avc_update_node: avc_alloc_node-->avc_reclaim_node-->avc_xperms_populate-->插入链表操作
*流程2:avc_compute_av-->avc_insert-->avc_xperms_populate-->插入链表操作
从上面的流程可以看出,avc_reclaim_node完了之后,接下来会去insert 1个 avc node到链表, 然后此时整个avc cache只有1个avc node, 如果此时其他进程来遍历它的avc node,就会遍历不到,以导致命中率有下降。
通过结合ramdump分析reclaim次数为什么增加这么多,
static struct avc_node *avc_alloc_node(void)
{
struct avc_node *node;
node = kmem_cache_zalloc(avc_node_cachep, GFP_NOWAIT);
if (!node)
goto out;
INIT_HLIST_NODE(&node->list);
avc_cache_stats_incr(allocations);
if (atomic_inc_return(&avc_cache.active_nodes) > avc_cache_threshold)
avc_reclaim_node();
out:
return node;
}
源码中有写道avc_cache.active_nodes大于某个阈值的时候,就回去reclaim, 那么就需要通过ramdump解析后,查看当时卡顿时候avc_cache.active_nodes变量值,以及avc_cache的状态来判断。
当时确认avc_cache.active_nodes超过了avc_cache_threshold这个阈值512, 而avc_cache里面只包含了一个node.
那么怎么解释avc_cache里面只包含了一个node呢?
实际上,一旦出现内存紧张的时候,调用这个api又频繁的时候,很可能会出现alloc node 成功2次(甚至更多次), 然而insert avc node失败1次,此时avc_cache.active_nodes自增数是按alloc node的次数来自增的,而自增之前avc_cache.active_nodes刚好是512(再增加1就会发生relaim的临界值),自增之后avc_cache.active_nodes变成了514,此时reclaim被触发,但只会avc_node_delete512次,也就是avc_cache.active_nodes只会自减512次,
那么514-512=2, 正常情况应该是1,因为avc_cache链表里面应该只剩下新插入链表的那个node。然而现在avc_cache.active_nodes却是2,实际上这种情况也可以理解为是一种泄露,是变量值的泄露。那么在内存紧张且次api调用又
频繁的情况,发生一次这样的情况下,avc_cache.active_nodes就会泄露一次,久而久之就会出现avc_cache.active_nodes的值是512,而这个512次都是泄露导致的,那么就会出现此时新增1个avc cache node, avc_cache.active_nodes就变成了
513,会去触发reclaim, 然后再把这个新增的node插如avc cache 链表,此时链表里面是不是只剩下这么一个刚插入的node。这也就解释了为什么从ramdump解释出来的avc_cache 状态里面只有一个avc cache node了。
所以一旦泄露次数达到了512次,那么每次去调用这个selinux avc api就会去触发avc_reclaim_node动作,最终导致基本所有的system api调用都变慢。
所以回过头来看,avc_cache.active_nodes没有合理的自减操作是这个问题的根本原因,它应该插件链表失败的时候去自减。
原因是上面源码里atomic_inc_return(&avc_cache.active_nodes)有这样一句话,增加了avc_cache.active_nodes值之后,也就是在alloc_node成功之后,并在插入链表失败的情况下,并没有去减1
操作,源码如下:
static struct avc_node *avc_insert(u32 ssid, u32 tsid, u16 tclass,
struct av_decision *avd,
struct avc_xperms_node *xp_node)
{
struct avc_node *pos, *node = NULL;
int hvalue;
unsigned long flag;
if (avc_latest_notif_update(avd->seqno, 1))
goto out;
node = avc_alloc_node();
if (node) {
struct hlist_head *head;
spinlock_t *lock;
int rc = 0;
hvalue = avc_hash(ssid, tsid, tclass);
avc_node_populate(node, ssid, tsid, tclass, avd);
rc = avc_xperms_populate(node, xp_node);
if (rc) {
//此处应该有减1操作,但并没有
kmem_cache_free(avc_node_cachep, node);
return NULL;
}
head = &avc_cache.slots[hvalue];
lock = &avc_cache.slots_lock[hvalue];
spin_lock_irqsave(lock, flag);
hlist_for_each_entry(pos, head, list) {
if (pos->ae.ssid == ssid &&
pos->ae.tsid == tsid &&
pos->ae.tclass == tclass) {
avc_node_replace(node, pos);
goto found;
}
}
hlist_add_head_rcu(&node->list, head);
found:
spin_unlock_irqrestore(lock, flag);
}
out:
return node;
}
//插入链表的函数
static int avc_xperms_populate(struct avc_node *node,
struct avc_xperms_node *src)
{
struct avc_xperms_node *dest;
struct avc_xperms_decision_node *dest_xpd;
struct avc_xperms_decision_node *src_xpd;
if (src->xp.len == 0)
return 0;
dest = avc_xperms_alloc();
if (!dest)
return -ENOMEM;
memcpy(dest->xp.drivers.p, src->xp.drivers.p, sizeof(dest->xp.drivers.p));
dest->xp.len = src->xp.len;
/* for each source xpd allocate a destination xpd and copy */
list_for_each_entry(src_xpd, &src->xpd_head, xpd_list) {
dest_xpd = avc_xperms_decision_alloc(src_xpd->xpd.used);
if (!dest_xpd)
goto error;
avc_copy_xperms_decision(&dest_xpd->xpd, &src_xpd->xpd);
list_add(&dest_xpd->xpd_list, &dest->xpd_head);
}
node->ae.xp_node = dest;
return 0;
error:
avc_xperms_free(dest);
return -ENOMEM;
}
所以在插入链表失败之后,应该主动去减1
修改方案如下:
static struct avc_node *avc_insert(u32 ssid, u32 tsid, u16 tclass,
struct av_decision *avd,
struct avc_xperms_node *xp_node)
{
struct avc_node *pos, *node = NULL;
int hvalue;
unsigned long flag;
......
hvalue = avc_hash(ssid, tsid, tclass);
avc_node_populate(node, ssid, tsid, tclass, avd);
rc = avc_xperms_populate(node, xp_node);
if (rc) {
atomic_dec(&avc_cache.active_nodes);
kmem_cache_free(avc_node_cachep, node);
return NULL;
}
......
found:
spin_unlock_irqrestore(lock, flag);
}
out:
return node;
}