这里介绍一个通过kernel的sys文件系统去debug binder的方法,我遇到的两类问题:1、binder leak 2、binder开启的线程已达上限造成后面的从上往下的call flow block住产生anr
1、binder leak就是binder内存泄漏,用于binder通信的buffer大概有4M左右(据同事描述,还没拷证具体数值),在binder通信中如果传输中使用的parcel没有有效release,会造成buffer空间越来越少,然后积累到一定程度,就会出现binder传输的消息在另外一端无法接收。
/***更正***/
在进程使用binder driver的时候,最大在kernel空间中开启的虚拟内存空间是4M。一般如果使用IPCThread的API去操作binder的时候是会自动往driver发送FREE_BUFFER的指令做释放操作,所以一般很难出现Binder leak的现象。除非是自己对binder去做IOctl。
2、binder线程到达上限。这个的情景就是app向service发起请求的频率过高,service端如果对所有的业务执行都加了锁的话,则会导致service端用于接收处理binder事件的线程全部卡住,当线程池(default 16个线程)耗尽之后,就无法再处理请求。如果这个时候app的主线程如果再调用该serivce提供的方法,就很容易出现anr
我要提的debug方法就是cat /sys/kernel/debug/binder这个目录下的文件来查看所有进程的使用binder的状况来确定是上述两种状况的哪一种,我主要是cat transactions这个文件来查看运行状况的,一般的打印如下:
proc代表进程号;一行buffer代表有一个binder通信在占用buffer的空间(具体其他打印的意义需要参考binder driver)
如果针对第一种binder leak的情况,在程序运行过程中该proc下的buffer的行数会越来越多,不停地增长,这样基本上你就能判断是binder leak的情况
另外一种状况的打印,其中有新增一类以thread开头的打印,这个代表的是进程具有的接收binder的线程,如果这类行数超多,16个,基本就可以确定是binder线程池已经满了
proc 1663
thread 1663: l 02
incoming transaction 73304: ffffffc07735c580 from 2364:3836 to 1663:1663 code 9 flags 10 pri 0 r1 node 9227 size 44:0 data ffffff8005580880
thread 2158: l 10
outgoing transaction 73630: ffffffc097d93c00 from 1663:2158 to 2364:0 code 1 flags 10 pri 0 r1 node 23731 size 92:0 data ffffff8005c81018
thread 2179: l 02
incoming transaction 73390: ffffffc09a2bdf80 from 2364:3879 to 1663:2179 code 9 flags 10 pri 0 r1 node 9227 size 44:0 data ffffff8005580370
thread 2968: l 01
incoming transaction 73402: ffffffc0b1df1600 from 2364:3859 to 1663:2968 code 20 flags 10 pri 0 r1 node 9227 size 60:0 data ffffff8005580900
thread 3328: l 01
incoming transaction 73340: ffffffc0b1df1c80 from 2364:3864 to 1663:3328 code 20 flags 10 pri 0 r1 node 9227 size 60:0 data ffffff8005580160
thread 3505: l 01
incoming transaction 73344: ffffffc0b1acd780 from 2364:3572 to 1663:3505 code 9 flags 10 pri 0 r1 node 9227 size 44:0 data ffffff8005580270
thread 3506: l 01
incoming transaction 73338: ffffffc0b1df1c00 from 2364:3320 to 1663:3506 code 9 flags 10 pri 0 r1 node 9227 size 44:0 data ffffff80055800e0
thread 3528: l 01
incoming transaction 73642: ffffffc0b0354500 from 2364:2377 to 1663:3528 code 3 flags 10 pri 0 r1 node 23734 size 72:0 data ffffff8005580a20
thread 3529: l 01
incoming transaction 73343: ffffffc09b223a00 from 2364:3321 to 1663:3529 code 9 flags 10 pri 0 r1 node 9227 size 44:0 data ffffff80055801f0
thread 3582: l 01
incoming transaction 73644: ffffffc077b0fc00 from 2364:3516 to 1663:3582 code 3 flags 10 pri 0 r1 node 23734 size 72:0 data ffffff8005580508
thread 3583: l 01
incoming transaction 73307: ffffffc098e91780 from 2364:3322 to 1663:3583 code 20 flags 10 pri 0 r1 node 9227 size 60:0 data ffffff8005580628
thread 3835: l 01
incoming transaction 73309: ffffffc0a3c8ae80 from 2364:3566 to 1663:3835 code 20 flags 10 pri 0 r1 node 9227 size 60:0 data ffffff8005580050
thread 3852: l 01
incoming transaction 73411: ffffffc0b0357200 from 2364:2379 to 1663:3852 code 9 flags 10 pri 0 r1 node 9227 size 44:0 data ffffff80055803f0
thread 3853: l 01
incoming transaction 73629: ffffffc0779a5500 from 2364:2942 to 1663:3853 code 9 flags 10 pri 0 r1 node 9227 size 44:0 data ffffff8005580470
thread 3874: l 01
incoming transaction 73400: ffffffc094b5e900 from 2364:3005 to 1663:3874 code 20 flags 10 pri 0 r1 node 9227 size 60:0 data ffffff80055807f0
thread 3875: l 01
incoming transaction 73308: ffffffc094b19a80 from 2364:3860 to 1663:3875 code 20 flags 10 pri 0 r1 node 9227 size 60:0 data ffffff80055806d0
thread 3889: l 01
incoming transaction 73384: ffffffc09907ea80 from 2364:3571 to 1663:3889 code 9 flags 10 pri 0 r1 node 9227 size 44:0 data ffffff80055802f0
thread 3892: l 01
incoming transaction 74866: ffffffc09919be00 from 1650:1816 to 1663:3892 code 4 flags 10 pri -8 r1 node 26532 size 44:0 data ffffff80055805a0
buffer 73309: ffffff8005580050 size 60:0 active
buffer 73338: ffffff80055800e0 size 44:0 active
buffer 73340: ffffff8005580160 size 60:0 active
buffer 73343: ffffff80055801f0 size 44:0 active
buffer 73344: ffffff8005580270 size 44:0 active
buffer 73384: ffffff80055802f0 size 44:0 active
buffer 73390: ffffff8005580370 size 44:0 active
buffer 73411: ffffff80055803f0 size 44:0 active
buffer 73629: ffffff8005580470 size 44:0 active
buffer 73644: ffffff8005580508 size 72:0 active
buffer 74866: ffffff80055805a0 size 44:0 active
buffer 73307: ffffff8005580628 size 60:0 active
buffer 73308: ffffff80055806d0 size 60:0 active
buffer 73400: ffffff80055807f0 size 60:0 active
buffer 73304: ffffff8005580880 size 44:0 active
buffer 73402: ffffff8005580900 size 60:0 active
buffer 43572: ffffff80055809a8 size 0:0 delivered
buffer 73642: ffffff8005580a20 size 72:0 active
为了进一步确认是否已经占满,用debuggerd去dump该进程获得其墓碑文件,就基本能看出来线程的情况,java的binder线程名大多是binder_1~binder_A ....之类的如果满16个就能确定了;native的bin档的话,线程名没有那么明确,但这些binder线程的名字都相同,也是如果满了16也能说明是该问题。
为解决这种线程池耗尽的问题,应该从app端去限制请求的频率,设定一定的时间间隔才能保证功能正常。
原文地址: https://zhuanlan.zhihu.com/p/22645229