一个关于binder的debug技巧

62 阅读 0 评论 41 点赞

我是靠谱客的博主虚拟寒风，最近开发中收集的这篇文章主要介绍一个关于binder的debug技巧，觉得挺不错的，现在分享给大家，希望可以做个参考。

概述

在android的C/S IPC通信框架中，常会遇到binder通信异常的问题（其实不是太经常会遇到，主要在煲机和压测等极限测试的情况下才会出现），binder的driver基本不用去怀疑其出bug的可能性，基本为0，如果binder通信出现问题，那么十有八九都是app或者service本身写的有问题造成的。

这里介绍一个通过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