Android 进阶——性能优化之因Handler引起句柄泄漏导致ANR的定位和解决

Posted 2022-07-28 CrazyMo_

tags:

篇首语：本文由小常识网(cha138.com)小编为大家整理，主要介绍了Android 进阶——性能优化之因Handler引起句柄泄漏导致ANR的定位和解决相关的知识，希望对你有一定的参考价值。

文章大纲

引言
一、场景重现
二、ANR
三、分析定位
四、优化修改

引言

一次测试在验证某种特殊情况下的用例时引Handler最终导致ANR，

一、场景重现

具体场景是包名为com.crazyai.whiteboard.systemui 的进程通过Binder 与包名为com.crazyai.voiceframework 进程通信，具体逻辑是包名为com.crazyai.whiteboard.systemui的进程通过直接调用com.crazyai.voiceframework.core.AIVoiceManager.disableWaken方法。

//com.crazyai.voiceframework.core.AIVoiceManager 
public int disableWaken() 
    MoLogUtil.d(TAG,"DUI#FRAMEWORK stop waken done");
    return postMessage(new WakeupMessage()
                       .setAction(Constants.Wakeup.ACTION.STOP)
                       .toRemoteMessage());


private int postMessage(@NonNull RemoteMessage message) 
    if (checkPrepare()) 
        try 
            //@link RemoteInteractImpl #callIPC
            return getBaseManager().callIPC(message);
         catch (Exception e) 
            e.printStackTrace();
        
    
    return ResultCode.RESULT_BIND_GET_ERROR;

而com.lamy.aivoiceserver.core.RemoteInteractImpl部分代码如下：

@Override
    public synchronized int callIPC(RemoteMessage remoteMessage) throws RemoteException 
         return processCall(remoteMessage);
    

    private int processCall(RemoteMessage message) 
        if(message!=null) 
        ...
            if(!TextUtils.isEmpty(msg)) 
                BaseCommand command = null;
                JSONObject object = null;
                try 
                    object = new JSONObject(msg);
                    command = new WakeupCommand(object);
                 catch (JSONException e) 
                    return ResultCode.RESULT_UNKNOWN_ERROR;
                
                if (command != null) 
                    command.callIPC(object);
                
                return ResultCode.RESULT_OK;
            
        
        return ResultCode.RESULT_UNKNOWN_ERROR;

问题就出在这里：

public class WakeupCommand extends BaseCommand 
    protected JSONObject cmdJson;
	 protected HandlerThread handlerThread;
    protected SyncHandler workHandler;
    //##罪魁祸首## 
    public WakeupCommand(@NonNull JSONObject json,RemoteInteractImpl impl) 
    	  super(json,impl);
        this.remoteInteract=impl;
        this.cmdJson = json;
        this.handlerThread = new HandlerThread("VBOT#"+TAG);
        this.handlerThread.start();
        this.workHandler = new SyncHandler(handlerThread.getLooper());
    
    ...

当我这个接口方法被短时间内通过Handler机制频繁调用的时候，一段时间后就会ANR。

二、ANR

1、ANR概述

当APP有一段时间响应不够灵敏，系统会向用户显示一个对话框，这个对话框称作“应用程序无响应”（Application Not Responding）对话框，用户可以选择“等待”而让程序继续运行，也可以选择“强制关闭”。如果开发机器上出现ANR问题时，系统会生成一个traces.txt的文件放在/data/anr下，最新的ANR信息在最开始部分。通过adb命令将其导出到本地：

$adb pull data/anr/traces.txt

2、ANR 的主要类型

KeyDispatchTimeout——主要是类型按键或触摸事件在5s内输入系统无响应
BroadcastTimeout——BroadcastReceiver在20s内无法处理完成
ServiceTimeout——小概率事件 Service在10s内无法处理完成

3、在android中默认场景限制（超出就会ANR）：

Activity的最长执行时间是5秒（主要类型）。
BroadcastReceiver的最长执行时间的则是10秒。
ServiceTimeout的最长执行时间是20秒（少数类型）。

4、当应用程序的UI线程响应超时才会引起ANR 的原因

当前事件没有机会处理，例如UI线程正在响应另外的事件，当前事件被某个事件给阻塞掉了。
当前事件正在处理但是由于耗时太长没有能及时的完成。
主线程被阻塞。
在BroadcastReceiver里的工作没有在10s内完成（可以使用IntentService替代），Service的任务耗时超过20s。
发生了死锁。
耗时操作的动画需要大量的计算工作，可能导致CPU负载过重。
主线程当中执行了耗时的计算（IO、网络操作等）。比如自定义控件的时候onDraw方法里面经常这么做。
（同时聊一聊自定义控件的性能优化：在onDraw里面创建对象容易导致内存抖动—绘制动作会大量不断调用，产生大量垃圾对象导致GC很频繁就造成了内存抖动。内存抖动就容易造成UI出现掉帧卡顿的问题）
Service执行了耗时的操作，因为Service也是在主线程当中执行的，Service生命周期的各个回调和其他的应用组件一样，是跑在主线程中，会影响到你的UI操作或者阻塞主线程中的其他事情，所以耗时操作应该在service里面开启子线程来做。
Activity的onCreate和onResume回调中执行耗时的操作。

UI线程主要包括如下：
Activity:onCreate(), onResume(), onDestroy(), onKeyDown(), onClick()
AsyncTask: onPreExecute(), onProgressUpdate(), onPostExecute(), onCancel()
Mainthread handler: handleMessage(), post(runnable r)

5、ANR优化N部曲

布局优化，使用herarchyviewer(视图层次窗口)工具。
删除无用的空间和层级，尽量避免过度绘制。
选择性能较低的viewgroup，比如在可以选择RelativeLayout也可以使用LinearLayout的情况下，优先使用LinearLayout，因为相对来说RelativeLayout功能较为复杂，会占用更多的CPU资源。
使用标签重用布局、减少层级、进行预加载（用的时候才加载）。
绘制优化，指view在onDraw方法中避免大量的耗时的操作，由于onDraw方法可能会被频繁的调用，尽量onDraw方法中不要创建新的局部变量，
ondraw方法被频繁的调用，很容易引起GC；ondraw方法不要做耗时的操作；。
线程优化，使用线程池来管理和复用线程，避免程序中出现大量的Thread。
为了执行一个长时间的耗时操作而创建一个工作线程最方便高效的方式是使用AsyncTask，只需要继承AsyncTask并实现doInBackground()方法来执行任务即可
开发过程中使用Thread或者HandlerThread，可以尝试调用Process.setThreadPriority(Process.THREAD_PRIORITY_BACKGROUND)设置较低的优先级，否则仍然会降低程序响应，因为默认Thread的优先级和主线程相同。
Activity的onCreate和onResume回调中尽量避免耗时的代码，应该尽可能的做比较少的事情，其实，任何执行在UI线程中的方法都应该尽可能简短快速。类似网络或者DB操作等可能长时间执行的操作，或者是类似调整bitmap大小等需要长时间计算的操作，都应该执行在工作线程中。
使用AsyncTask处理耗时的IO等操作。
使用Thread或者HandlerThread时，使用Process.setThreadPriority(Process.THREAD_PRIORITY_BACKGROUND)或者java.lang.Thread.setPriority （int priority）设置优先级为后台优先级，这样可以让其他的多线程并发消耗CPU的时间会减少，有利于主线程的处理。

三、分析定位

1、分析APLOG

通常发生ANR的时候APLOG 一般会有明显的关键字 ANR，从日志中我们可以得到几条关键的线索：

AIVoiceManager 的是在PID为2906的进程中被调用
WakeupCommand是运行在PID为3459的进程中
包名为com.crazyai.whiteboard.systemui的进程内部PID为2906 的线程在等待了5531.5 ms 后输入超时未得到相应导致ANR

...
01-07 09:38:26.039 I/AIVoiceManager->->( 2906): ★【IPC_1.0】RemoteMessage="WakeupMessage":"action":1★
01-07 09:38:26.039 I/RemoteInteractImpl->( 3549): ★【IPC_1.1】RemoteMessage="WakeupMessage":"action":1★
01-07 09:38:26.040 I/CommandFactory->( 3549): ★【IPC_1.2】command=com.crazyai.aivoiceserver.command.WakeupCommand@8ee4aa1★
01-07 09:38:26.041 I/WakeupCommand->->( 3549): ★【IPC_1.3】【Wake】message="WakeupMessage":"action":1★
01-07 09:38:26.041 D/DUIBot->( 3549): ¤DUI#TTS init=false,ASR init=false,Wake init=false¤
01-07 09:38:26.041 W/DUIBot->( 3549): caused by $com.crazyai.libduivoice.DUIVoiceBot on line 588 call disableWaken DUI#VBOT no need close!$
01-07 09:38:26.042 D/VoiceAssistant( 2906): VoiceAssistant removeView null
01-07 09:39:16.757 E/ActivityManager( 2420): ANR in com.crazyai.whiteboard.systemui
01-07 09:39:16.757 E/ActivityManager( 2420): PID: 2906
01-07 09:39:16.757 E/ActivityManager( 2420): Reason: Input dispatching timed out (Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago.  Wait queue length: 6.  Wait queue head age: 5531.5ms.)
01-07 09:39:16.757 E/ActivityManager( 2420): Load: 14.27 / 13.19 / 10.4
01-07 09:39:16.757 E/ActivityManager( 2420): CPU usage from 0ms to 5319ms later (2021-01-07 09:39:11.385 to 2021-01-07 09:39:16.705):
01-07 09:39:16.757 E/ActivityManager( 2420):   48% 2420/system_server: 31% user + 17% kernel / faults: 3809 minor 8 major
01-07 09:39:16.757 E/ActivityManager( 2420):   13% 2087/vendor.hisilicon.hardware.hwtvmw@1.0-service: 4.8% user + 8.2% kernel
01-07 09:39:16.757 E/ActivityManager( 2420):   11% 3978/com.ecloud.eairplay: 9.7% user + 1.6% kernel / faults: 1240 minor
01-07 09:39:16.757 E/ActivityManager( 2420):   9.9% 1291/HI_VPSS_Process: 0% user + 9.9% kernel
01-07 09:39:16.757 E/ActivityManager( 2420):   9.9% 2906/com.crazyai.whiteboard.systemui: 7.1% user + 2.8% kernel / faults: 1301 minor 2 major
01-07 09:39:16.757 E/ActivityManager( 2420):   9% 2098/surfaceflinger: 4.1% user + 4.8% kernel / faults: 694 minor
01-07 09:39:16.757 E/ActivityManager( 2420):   6.5% 2243/pqserver: 0.7% user + 5.8% kernel
01-07 09:39:16.757 E/ActivityManager( 2420):   3% 2892/com.hisilicon.tvui: 1.8% user + 1.1% kernel / faults: 798 minor
01-07 09:39:16.757 E/ActivityManager( 2420):   2.6% 2223/audioserver: 1.5% user + 1.1% kernel / faults: 118 minor
01-07 09:39:16.757 E/ActivityManager( 2420):   0% 3392/com.crazyai.timemanager: 0% user + 0% kernel / faults: 1095 minor
...

以上就是从APLOG得到的全部线索，尤其记住记住以上两个PID。

2、分析/data/anr/trace.txt

/data/anr/trace.txt文件是用于ANR时保存各进程/线程当时堆栈快照详细信息的：前面是线程名称，sysTid为进程/线程Id，pc代表PC 计数器，括号内为函数入口地址的偏移量等。

.......
"main" prio=5 tid=1 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x73658810 self=0x7c3aebea00
  | sysTid=2906 nice=0 cgrp=default sched=0/0 handle=0x7c3f6a19b0
  | state=S schedstat=( 0 0 0 ) utm=999 stm=279 core=3 HZ=100
  | stack=0x7fe11c7000-0x7fe11c9000 stackSize=8MB
  | held mutexes=
  kernel: __switch_to+0x90/0xb8
  kernel: binder_thread_read+0x444/0x1008
  kernel: binder_ioctl_write_read+0x16c/0x318
  kernel: binder_ioctl+0x514/0x760
  kernel: do_vfs_ioctl+0xb0/0x760
  kernel: SyS_ioctl+0x94/0xa8
  kernel: el0_svc_naked+0x24/0x28
  native: #00 pc 00000000000686bc  /system/lib64/libc.so (__ioctl+4)
  native: #01 pc 0000000000023ed0  /system/lib64/libc.so (ioctl+132)
  native: #02 pc 0000000000061aa8  /system/lib64/libbinder.so (_ZN7android14IPCThreadState14talkWithDriverEb+256)
  native: #03 pc 0000000000062840  /system/lib64/libbinder.so (_ZN7android14IPCThreadState15waitForResponseEPNS_6ParcelEPi+340)
  native: #04 pc 0000000000062560  /system/lib64/libbinder.so (_ZN7android14IPCThreadState8transactEijRKNS_6ParcelEPS1_j+216)
  native: #05 pc 0000000000056e30  /system/lib64/libbinder.so (_ZN7android8BpBinder8transactEjRKNS_6ParcelEPS1_j+72)
  native: #06 pc 0000000000121500  /system/lib64/libandroid_runtime.so (???)
  native: #07 pc 0000000000933cb4  /system/framework/arm64/boot-framework.oat (Java_android_os_BinderProxy_transactNative__ILandroid_os_Parcel_2Landroid_os_Parcel_2I+196)
  at android.os.BinderProxy.transactNative(Native method)
  at android.os.BinderProxy.transact(Binder.java:748)
  at com.crazyai.voiceframework.IRemoteInteract$Stub$Proxy.callIPC(IRemoteInteract.java:7)
  at com.crazyai.voiceframework.core.AIVoiceManager.postMessage(AIVoiceManager.java:3)
  at com.crazyai.voiceframework.core.AIVoiceManager.disableWaken(AIVoiceManager.java:5)
  at com.crazyai.whiteboard.systemui.voice.VoiceAssistant.disable(VoiceAssistant.kt:1)
  at com.crazyai.whiteboard.systemui.voice.VoiceAssistant.initAssistant(VoiceAssistant.kt:4)
  at com.crazyai.whiteboard.systemui.voice.VoiceAssistant.access$initAssistant(VoiceAssistant.kt:1)
  at com.crazyai.whiteboard.systemui.voice.VoiceAssistant$readyReceiver$1$a.run(VoiceAssistant.kt:1)
  at android.os.Handler.handleCallback(Handler.java:789)
  at android.os.Handler.dispatchMessage(Handler.java:98)
  at android.os.Looper.loop(Looper.java:164)
  at android.app.ActivityThread.main(ActivityThread.java:6553)
  at java.lang.reflect.Method.invoke(Native method)
  at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:240)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:767)
  ....

从trace文件可以初步得出包名为com.crazyai.whiteboard.systemui 与包名为com.crazyai.voiceframework 通过Binder进行通信时，调用链为com.crazyai.whiteboard.systemui.voice.VoiceAssistant.disable–>com.crazyai.voiceframework.core.AIVoiceManager.disableWaken–>com.crazyai.voiceframework.core.AIVoiceManager.postMessage–>com.crazyai.voiceframework.IRemoteInteractImpl.callIPC导致了ANR。但是还是看不出什么原因。

3、分析/data/tombstones目录下的文件

/data/tombstones目录下的文件，当运行在Linux Kernel内核之上的Android系统出现异常时，一般会自动重启Android层的，但可能导致问题很难复现定位debug，于是当Android层出现异常就会将进程的上下文信息保存到墓碑tombstone（进程下所属的所有线程的堆栈信息），主要包括：

标准开头是标志性log开始 " * * * * * * * * * * * * * * "

dump_header_info打印头信息

dump_thread_info打印thread信息

dump_signal_info打印信号信息

dump_probable_cause打印可能原因信息

dump_registers打印寄存器信息

log_backtrace打印backtrace的信息

dump_stack打印stack的信息

dump_memory_and_code打印memory的信息

dump_all_maps打印map的信息

dump_log_file(log, pid, “system”, tail);打印system log的信息

dump_log_file(log, pid, “main”, tail);打印mainlog的信息

当Native进程发生了异常，比如NULL指针
操作系统会去异常向量表的地址去处理异常，然后发送信号
在debuggred_init注册的信号处理函数就会收到处理
创建伪线程去启动crash_dump进程，crash_dump则会获取当前进程中各个线程的crash信息
tombstoned进程是开机就启动的，开机时注册好了socket等待监听
当在crash_dump中去连接tombstoned进程的时候，根据传递的dump_type类型会返回一个/data/tombstones/下文件描述符
crash_dump进程后续通过engrave_tombstone函数将所有的线程的详细信息写入到tombstone文件中
则就在/data/tombstones下生成了此次对应的tombstone_XX文件

文件格式形如tombstone_00，以下为部分关键信息，在pid为3549的进程下以VBOT#WakeupComm为名的线程在短时间内被创建了300多条，Binder线程池内部的线程也创建了100多条且TID 均不同，而且最关键是看到了由于'Could not create epoll instance: Too many open files内核发出了SIGABRT 信号，

*** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
Build fingerprint: 'unknown'
Revision: '0'
ABI: 'arm64'
pid: 3549, tid: 10427, name: VBOT#WakeupComm  >>> com.lamy.aivoiceserver <<<
signal 6 (SIGABRT), code -6 (SI_TKILL), fault addr --------
Abort message: 'Could not create epoll instance: Too many open files'
    x0   0000000000000000  x1   00000000000028bb  x2   0000000000000006  x3   0000000000000008
    x4   0000000000000000  x5   0000000000000000  x6   0000000000000000  x7   7f7f7f7f7f7f7f7f
    x8   0000000000000083  x9   bdee45110d16c533  x10  0000000000000000  x11  0000000000000001
    x12  ffffffffffffffff  x13  ffffffffffffffff  x14  ff00000000000000  x15  ffffffffffffffff
    x16  0000007c3d173308  x17  0000007c3d1155d0  x18  0000007c3acee480  x19  0000000000000ddd
    x20  00000000000028bb  x21  00000000703fb870  x22  00000000000028bb  x23  0000000000000001
    x24  00000000703a2da8  x25  0000000013080088  x26  00000000130800b0  x27  0000000013080100
    x28  0000007c3adc4000  x29  0000007c00ffd950  x30  0000007c3d0c9994
    sp   0000007c00ffd910  pc   0000007c3d1155d8  pstate 0000000060000000
    v0   2e2e2e2e2e2e2e2e2e2e2e2e2e2e2e2e  v1   0000007c3d1d59800000007c00ffd830
    v2   2e6761742e676f6c2e74736973726570  v3   80200800000000008020080080000000
    v4   00000000000000000000000000000000  v5   00000000000000000000000000000000
    v6   40000000400000004000000000000000  v7   80200802802008028020080280200802
    v8   00000000000000000000000000000000  v9   00000000000000000000000000000000
    v10  00000000000000000000000000000000  v11  00000000000000000000000000000000
    v12  00000000000000000000000000000000  v13  00000000000000000000000000000000
    v14  00000000000000000000000000000000  v15  00000000000000000000000000000000
    v16  40100401401004014010040140100401  v17  400040004000000040404000a800a880
    v18  40000000400000004000000000000000  v19  00000000000000000000007c00000000
    v20  00000000000000000000007cffe5b533  v21  00000000000000003a000088ffe5b533
    v22  000000000000000000ffffffffffffff  v23  00000000000000000000000000000000
    v24  00000000000000003afd5f以上是关于Android 进阶——性能优化之因Handler引起句柄泄漏导致ANR的定位和解决的主要内容，如果未能解决你的问题，请参考以下文章 
 Android 进阶——性能优化之因Handler引起句柄泄漏导致ANR的定位和解决
 ［Android进阶］Android性能优化
 Android进阶知识——Android性能优化
 Android进阶知识——Android性能优化
 Android进阶知识——Android性能优化
 Android进阶知识——Android性能优化