一个看似是系统问题的应用问题的解决过程
发布日期:2021-06-30 18:42:16 浏览次数:3 分类:技术文章

本文共 7739 字,大约阅读时间需要 25 分钟。

作者:王小二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通信,内核发生了什么,请看下面图,看懂下图,才能知道我在说什么:

640?wx_fmt=png

References

[1] [007]一次Binder通信最大可以传输多大的数据? 简书地址:https://www.jianshu.com/p/ea4fc6aefaa8

640?wx_fmt=jpeg

转载地址:https://linus.blog.csdn.net/article/details/100570446 如侵犯您的版权,请留言回复原文章的地址,我们会给您删除此文章,给您带来不便请您谅解!

上一篇:终于赢球了
下一篇:Linux 内核宏 time_after解析

发表评论

最新留言

哈哈,博客排版真的漂亮呢~
[***.90.31.176]2024年04月30日 22时05分23秒