[011]一个看似是系统问题的应用问题的解决过程
前言
今天遇到一个问题，应用工程师分析是系统层的问题，然后就把这个锅给了我。最后我又把锅甩回给了应用工程师。
异常log如下:
I [2019-08-18 10:11:08 GMT+8] binder: 1433:1561 transaction failed 29201/-28, size 828-8 line 3135
W BroadcastQueue: Can't deliver broadcast to com.xxxx.xxxxx (pid 4712). Crashing it.
W BroadcastQueue: Failure sending broadcast Intent { act=android.intent.action.BATTERY_CHANGED flg=0x60000010 (has extras) }
W BroadcastQueue: android.os.DeadObjectException: Transaction failed on small parcel; remote process probably died
W BroadcastQueue: at android.os.BinderProxy.transactNative(Native Method)
W BroadcastQueue: at android.os.BinderProxy.transact(Binder.java:1127)
W BroadcastQueue: at android.app.IApplicationThread$Stub$Proxy.scheduleRegisteredReceiver(IApplicationThread.java:1237)
W BroadcastQueue: at com.android.server.am.BroadcastQueue.performReceiveLocked(BroadcastQueue.java:496)
W BroadcastQueue: at com.android.server.am.BroadcastQueue.deliverToRegisteredReceiverLocked(BroadcastQueue.java:715)
W BroadcastQueue: at com.android.server.am.BroadcastQueue.processNextBroadcastLocked(BroadcastQueue.java:875)
W BroadcastQueue: at com.android.server.am.BroadcastQueue.processNextBroadcast(BroadcastQueue.java:834)
W BroadcastQueue: at com.android.server.am.BroadcastQueue$BroadcastHandler.handleMessage(BroadcastQueue.java:172)
W BroadcastQueue: at android.os.Handler.dispatchMessage(Handler.java:106)
W BroadcastQueue: at android.os.Looper.loop(Looper.java:193)
W BroadcastQueue: at android.os.HandlerThread.run(HandlerThread.java:65)
W BroadcastQueue: at com.android.server.ServiceThread.run(ServiceThread.java:44)
初步分析
从log来看的确好像是binder驱动第3135行出现问题（line 3135）
binder: 1433:1561 transaction failed 29201/-28, size 828-8 line 3135
一看Binder.c的代码发现对不上3135行，估计是编译版本不一样，因为测试是user版本，代码优化了，这怎么办？我需要在userdebug的版本上你复现此问题。
Binder.c
3129 if (target_node && target_node->txn_security_ctx) {
3130 u32 secid;
3131 size_t added_size;
3132
3133 security_task_getsecid(proc->tsk, &secid);
3134 ret = security_secid_to_secctx(secid, &secctx, &secctx_sz);
3135 if (ret) {
3136 return_error = BR_FAILED_REPLY;
3137 return_error_param = ret;
3138 return_error_line = __LINE__;
3139 goto err_get_secctx_failed;
3140 }
聪明机智的我瞬间判断应该是对应到3164行，应该是binder server无法申请足够的buffer，别问我怎么想到的，有时候解决问题就得靠猜。
3154 t->buffer = binder_alloc_new_buf(&target_proc->alloc, tr->data_size,
3155 tr->offsets_size, extra_buffers_size,
3156 !reply && (t->flags & TF_ONE_WAY));
3157 if (IS_ERR(t->buffer)) {
3158 /*
3159 * -ESRCH indicates VMA cleared. The target is dying.
3160 */
3161 return_error_param = PTR_ERR(t->buffer);
3162 return_error = return_error_param == -ESRCH ?
3163 BR_DEAD_REPLY : BR_FAILED_REPLY;
3164 return_error_line = __LINE__;
3165 t->buffer = NULL;
3166 goto err_binder_alloc_buf_failed;
3167 }
为了证明我判断是对的，我写了如下的一个demo安装到userdebug来制造binder server无法申请足够的buffer的情况
public class MainActivity extends Activity implements View.OnClickListener {
private MyLinear mRoot;
private IMyAidlInterface myAidlInterface;
@Override
protected void onCreate(Bundle savedInstanceState) {
super.onCreate(savedInstanceState);
setContentView(R.layout.activity_main);
mRoot = (MyLinear) findViewById(R.id.root);
mRoot.setOnClickListener(this);
Intent intent = new Intent(this, MyService.class);
bindService(intent, new ServiceConnection() {
@Override
public void onServiceConnected(ComponentName name, IBinder service) {
myAidlInterface = IMyAidlInterface.Stub.asInterface(service);
}
@Override
public void onServiceDisconnected(ComponentName name) {
}
}, Context.BIND_AUTO_CREATE);
}
@Override
public void onClick(View v) {
try {
while (true) {
myAidlInterface.send("dfdafsdfafdasdfadfadsfafd");
}
} catch (Exception e) {
}
}
}
public class MyService extends Service {
@Override
public IBinder onBind(Intent intent) {
return new MyBinder();
}
public class MyBinder extends IMyAidlInterface.Stub {
@Override
public void send(String e) throws RemoteException {
//后面发现这个4秒的卡顿，不加也可以复现此问题
try {
Thread.sleep(4000);
} catch (Exception ee) {
}
}
}
}
// IMyAidlInterface.aidl
package com.tct.activitydemo;
// Declare any non-default types here with import statements
interface IMyAidlInterface {
/**
* Demonstrates some basic types that you can use as parameters
* and return values in AIDL.
*/
oneway void send(String e);
}
出现的异常log，和之前log相比，除了行数不对，error code是一样的都是29201/-28，而且行数果然是3164行，所以我的推测是对的。
//binder: 1433:1561 transaction failed 29201/-28, size 828-8 line 3135
binder: 30286:30286 transaction failed 29201/-28, size 140-0 line 3164
初步分析结论
广播的发送失败是原因，在一次binder通信中，无法向广播注册的App的binder驱动中映射的共享内存申请足够buffer。
重大发现
我发现出问题的应用注册了300多个广播，都是监听android.intent.action.BATTERY_CHANGED，具体log就不贴了，在bugreport中会有当前系统所有广播的dumpsys的信息。我贴出meminfo的信息，发现三百多个activity没有被GC，因为那个广播是在activity中被动态注册的，所以变相可以证明注册了300多个广播
** MEMINFO in pid 4712 [com.xxxxxxxxxxx] **
.....省略没用的信息，看下面activity的数量是325
Objects
Views: 13600 ViewRootImpl: 2
AppContexts: 329 Activities: 325
Assets: 3 AssetManagers: 0
Local Binders: 352 Proxy Binders: 366
Parcel memory: 887 Parcel count: 2235
Death Recipients: 2 OpenSSL Sockets: 0
WebViews: 0
推测
当这个广播发送的时候，由于他的接受者有300多个，每一次接收都会在申请一次buffer，如果短时间一下子申请，非常有可能超过binder驱动的(1mb-8kb)/2的限制，有人会问为什么是(1mb-8kb)/2而不是1mb-8kb，因为scheduleRegisteredReceiver是oneway的，对这个有疑问的，可以看一下我的另外一个文章：[007]一次Binder通信最大可以传输多大的数据？
进一步分析
其实一般分析到这里，对于我来说已经可以把锅甩回给了应用层，但是这个问题的好奇心促使我继续分析下去，一定要找到广播重复注册的原因。
涉及的保密，我把应用层代码的精简成自己的代码
public class MyActivity extends Activity {
private MyReceiver receiver;
@Override
protected void onCreate(Bundle savedInstanceState) {
super.onCreate(savedInstanceState);
setContentView(R.layout.activity_main2);
IntentFilter intentFilter = new IntentFilter();
intentFilter.addAction("fdafdafsdafaffasdfad");
receiver = new MyReceiver(this);
getApplication().registerReceiver(receiver, intentFilter);
}
@Override
protected void onDestroy() {
try {
//因为上下文不同，会导致unregisterReceiver失败，从而导致MyActivity和MyReceiver，无法被GC
unregisterReceiver(receiver);
} catch (Exception e) {
}
super.onDestroy();
}
public static class MyReceiver extends BroadcastReceiver {
private Context mContext;
public MyReceiver(Context context) {
mContext = context;
}
@Override
public void onReceive(Context context, Intent intent) {
}
}
}
水落石出
原来应用开发工程师，在registerReceiver和unregisterReceiver使用了不同的context，导致了unregisterReceiver的失败，从而导致MyReceiver的无法被释放，而且这个代码还会导致MyActivity的内存泄露。
举个例子来还原一下这个现场
小明寄了一份投诉信到信访局门口的信箱，然后信访局的1号工作人员拿了这份投诉信，进行处理。这个就是一次完整的oneway的binder通信。但是有一天小明一下子拿了300封投诉信，一封封的塞到信箱里，然后信访局的1~16号工作人员同时拿了16封信进行处理，但是还是架不住小明的塞信的速度，很快信箱就爆了，小明说了一句：垃圾信访局，我信还没有塞完呢。
2020年1月8日更新：
其实我上述例子这个解释中有点错误，结果一直没有人提出来，我更新一下，对于oneway的binder通信，server端的进程一次只有一个binder线程处理一个oneway的binder请求。
所以更正例子来还原一下现场：
小明寄了一份投诉信到信访局门口的信箱，然后信访局的1号工作人员拿了这份投诉信，进行处理。这个就是一次完整的oneway的binder通信。但是有一天小明一下子拿了300封投诉信，一封封的塞到信箱里，然后因为只有信访局的1号工作人员处理小明投诉，很快信箱就爆了，小明说了一句：垃圾信访局，我信还没有塞完呢。
其实大家可能有点难以理解一次binder通信，内核发生了什么，请看下面图，看懂下图，才能知道我在说什么：
binder通信
