作者:王小二C 2019/09/04
前言
今天遇到一个问题,应用工程师分析是系统层的问题,然后就把这个锅给了我。最后我又把锅甩回给了应用工程师。
异常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封信进行处理,但是还是架不住小明的塞信的速度,很快信箱就爆了,小明说了一句:垃圾信访局,我信还没有塞完呢。
其实大家可能有点难以理解一次binder通信,内核发生了什么,请看下面图,看懂下图,才能知道我在说什么:
References
[1] [007]一次Binder通信最大可以传输多大的数据? 简书地址:https://www.jianshu.com/p/ea4fc6aefaa8