前往小程序,Get更优阅读体验!
立即前往
首页
学习
活动
专区
工具
TVP
发布
社区首页 >专栏 >[068]破局ANR

[068]破局ANR

作者头像
王小二
发布2022-05-14 09:22:05
1.6K0
发布2022-05-14 09:22:05
举报
文章被收录于专栏:王小二的Android站

前言

ANR是Android中经常遇到的问题,常规的ANR问题,一般可以通过adb日志和trace文件,找到导致ANR的原因,但是有很多偶发的ANR问题,难以采用常规的手段来分析的,通过学习字节跳动整治ANR的系列文章,聊聊自己的感悟。

字节跳动技术团队整治ANR系列文章

一、工程师的噩梦

如下主线程的trace日志,想必这个日志是工程师的噩梦,为什么是噩梦?因为一般遇到这种日志,如果应用的日志不多,系统的日志不多,基本就是无解的存在。

代码语言:javascript
复制
android.os.MessageQueue.nativePollOnce(Native Method)
android.os.MessageQueue.next(MessageQueue.java:337)
android.os.Looper.loopOnce(Looper.java:184)
android.os.Looper.loop(Looper.java:324)
android.app.ActivityThread.main(ActivityThread.java:8140)
java.lang.reflect.Method.invoke(Native Method)
com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:559)
com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1009)

二、字节整治ANR法宝

字节整治ANR的两大法宝,Raster和Sliver

2.1 Raster

Raster主要作用:记录主线程Message历史信息

2.2 Sliver

Sliver主要作用:记录线程历史堆栈调用信息

小结

由于这两个功能的代码并没有开源,我自己简单的实现一下部分功能,来验证一下,这两个法宝能否真正的破局ANR。

三、制造一个ANR现场

首先制造一个ANR的现场,方便后面验证,代码也很简单,只需要两个类。 这个代码进入界面以后,按两下back键就可以出现ANR

代码语言:javascript
复制
public class MainActivity extends AppCompatActivity {

    @Override
    protected void onCreate(Bundle savedInstanceState) {
        super.onCreate(savedInstanceState);
    }

    @Override
    protected void onResume() {
        super.onResume();
        Intent intent = new Intent(this, Service.class);
        this.startService(intent);
    }
}

public class Service extends android.app.Service {
    @Nullable
    @Override
    public IBinder onBind(Intent intent) {
        return null;
    }

    @Override
    public void onCreate() {
        super.onCreate();
        try {
            Thread.sleep(7000);
        } catch (Exception e) {
            e.printStackTrace();
        }
    }
}

四、简化版Raster和Sliver设计

4.1 简化版Raster

保存并打印历史Message以及待处理的Message

4.2 简化版的Sliver

直接调用如下代码打印主线程的堆栈。

代码语言:javascript
复制
Looper.getMainLooper().getThread().getStackTrace()

4.3 触发的时间

在am_anr和ANR in的两个时机同时触发一次简化版Raster和Sliver, am_anr比较接近ANR触发点, ANR in其实是ANR触发以后,过了一段时间了。

五、实践

如下是我使用简化版的Raster和Sliver抓到的日志

5.1 am_anr时候触发

代码语言:javascript
复制
-----------HISTORY MSG-----------
Current Time:70022
Working Message:start=64631 delay=278ms took=0ms repeat=0 { when=0 what=114 obj=CreateServiceData{token=android.os.BinderProxy@2d85d09 className=com.kobe.fpstest.Service packageName=com.kobe.fpstest intent=null} target=android.app.ActivityThread$H }
Message 0 :start=64150 delay=5ms took=3ms repeat=0 { when=0 what=162 obj=/data/user/0/com.kobe.fpstest target=android.app.ActivityThread$H }
Message 1 :start=64153 delay=2ms took=1ms repeat=0 { when=0 what=138 obj=Bundle[mParcelledData.dataSize=1172] target=android.app.ActivityThread$H }
Message 2 :start=64154 delay=3ms took=73ms repeat=0 { when=0 what=110 obj=AppBindData{appInfo=ApplicationInfo{a8c29d6 com.kobe.fpstest}} target=android.app.ActivityThread$H }
Message 3 :start=64227 delay=75ms took=151ms repeat=0 { when=0 what=159 obj=android.app.servertransaction.ClientTransaction@5058edb0 target=android.app.ActivityThread$H }
Message 4 :start=64378 delay=225ms took=0ms repeat=0 { when=0 what=159 obj=android.app.servertransaction.ClientTransaction@3f67e3d1 target=android.app.ActivityThread$H }
Message 5 :start=64378 delay=154ms took=1ms repeat=0 { when=0 what=164 obj=com.kobe.fpstest target=android.app.ActivityThread$H }
Message 6 :start=64379 delay=33ms took=0ms repeat=0 { when=0 callback=androidx.core.content.res.ResourcesCompat$FontCallback$2 target=android.os.Handler }
-----------TODO MSG-----------
Message 0 :{ when=-5s670ms what=115 obj=ServiceArgsData{token=android.os.BinderProxy@2d85d09 startId=1 args=Intent { cmp=com.kobe.fpstest/.Service }} target=android.app.ActivityThread$H }
Message 1 :{ when=-5s659ms callback=android.view.ViewRootImpl$4 target=android.view.ViewRootImpl$ViewRootHandler }
Message 2 :{ when=-5s653ms barrier=0 }
Message 3 :{ when=-5s643ms callback=android.view.Choreographer$FrameDisplayEventReceiver target=android.view.Choreographer$FrameHandler }
Message 4 :{ when=-5s91ms what=8 arg1=1 target=android.view.ViewRootImpl$ViewRootHandler }
Message 5 :{ when=-5s91ms what=149 obj=android.os.BinderProxy@fd199f1 target=android.app.ActivityThread$H }
Message 6 :{ when=-4s873ms callback=android.app.ActivityThread$$ExternalSyntheticLambda1 target=android.app.ActivityThread$H }
-----------MAIN THREAD STACK-----------
java.lang.Thread.sleep(Native Method)
java.lang.Thread.sleep(Thread.java:451)
java.lang.Thread.sleep(Thread.java:356)
com.kobe.fpstest.Service.onCreate(Service.java:25)
android.app.ActivityThread.handleCreateService(ActivityThread.java:4664)
android.app.ActivityThread.access$1700(ActivityThread.java:281)
android.app.ActivityThread$H.handleMessage(ActivityThread.java:2212)
android.os.Handler.dispatchMessage(Handler.java:106)
android.os.Looper.loopOnce(Looper.java:231)
android.os.Looper.loop(Looper.java:324)
android.app.ActivityThread.main(ActivityThread.java:8140)
java.lang.reflect.Method.invoke(Native Method)
com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:559)
com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1009)

可以看到Working Message的start是64631,Current Time是70022,也就说这个Message目前已经运行了70022-64631=5391,也就是5.3秒。

正好堆栈抓到了java.lang.Thread.sleep(Native Method),这个堆栈又是属于Working Message。

5.2 ANR in时候触发

代码语言:javascript
复制
-----------HISTORY MSG-----------
Current Time:75887
Working Message:null
Message 0 :start=64631 delay=278ms took=7002ms repeat=0 { when=0 what=114 obj=CreateServiceData{token=android.os.BinderProxy@2d85d09 className=com.kobe.fpstest.Service packageName=com.kobe.fpstest intent=null} target=android.app.ActivityThread$H }
Message 1 :start=71633 delay=7280ms took=2ms repeat=0 { when=0 what=115 obj=ServiceArgsData{token=android.os.BinderProxy@2d85d09 startId=1 args=Intent { cmp=com.kobe.fpstest/.Service }} target=android.app.ActivityThread$H }
Message 2 :start=71635 delay=7270ms took=2ms repeat=0 { when=0 callback=android.view.ViewRootImpl$4 target=android.view.ViewRootImpl$ViewRootHandler }
Message 3 :start=71637 delay=7255ms took=137ms repeat=0 { when=0 callback=android.view.Choreographer$FrameDisplayEventReceiver target=android.view.Choreographer$FrameHandler }
Message 4 :start=71774 delay=71774ms took=1ms repeat=0 { when=0 callback=android.view.ViewRootImpl$$ExternalSyntheticLambda12 target=android.view.ViewRootImpl$ViewRootHandler }
Message 5 :start=71775 delay=6841ms took=0ms repeat=0 { when=0 what=8 arg1=1 target=android.view.ViewRootImpl$ViewRootHandler }
Message 6 :start=71775 delay=6841ms took=0ms repeat=0 { when=0 what=149 obj=android.os.BinderProxy@fd199f1 target=android.app.ActivityThread$H }
Message 7 :start=71775 delay=6622ms took=1ms repeat=0 { when=0 callback=android.app.ActivityThread$$ExternalSyntheticLambda1 target=android.app.ActivityThread$H }
Message 8 :start=71776 delay=136ms took=49ms repeat=0 { when=0 callback=androidx.appcompat.app.AppCompatDelegateImpl$2 target=android.view.ViewRootImpl$ViewRootHandler }
Message 9 :start=71826 delay=139ms took=2ms repeat=0 { when=0 what=31 obj=com.android.internal.os.SomeArgs@bd1a441 target=android.view.ViewRootImpl$ViewRootHandler }
Message 10 :start=71832 delay=21ms took=2ms repeat=0 { when=0 callback=android.view.Choreographer$FrameDisplayEventReceiver target=android.view.Choreographer$FrameHandler }
Message 11 :start=71834 delay=8ms took=0ms repeat=0 { when=0 what=6 target=android.view.ViewRootImpl$ViewRootHandler }
Message 12 :start=71834 delay=5ms took=0ms repeat=0 { when=0 what=13 target=android.view.ViewRootImpl$ViewRootHandler }
Message 13 :start=71834 delay=3ms took=0ms repeat=0 { when=0 what=4 arg1=1 obj=false target=android.view.inputmethod.InputMethodManager$H }
Message 14 :start=71840 delay=0ms took=1ms repeat=0 { when=0 what=2 obj=InputBindResult{result=SUCCESS_WITH_IME_SESSION method=com.android.internal.view.IInputMethodSession$Stub$Proxy@394ede6 id=com.google.android.inputmethod.latin/com.android.inputmethod.latin.LatinIME sequence=2 isInputMethodSuppressingSpellChecker=false} target=android.view.inputmethod.InputMethodManager$H }
Message 15 :start=71842 delay=0ms took=0ms repeat=0 { when=0 what=10 target=android.view.inputmethod.InputMethodManager$H }
Message 16 :start=71850 delay=0ms took=1ms repeat=0 { when=0 what=31 obj=com.android.internal.os.SomeArgs@bd1a441 target=android.view.ViewRootImpl$ViewRootHandler }
-----------TODO MSG-----------
-----------MAIN THREAD STACK-----------
android.os.MessageQueue.nativePollOnce(Native Method)
android.os.MessageQueue.next(MessageQueue.java:337)
android.os.Looper.loopOnce(Looper.java:184)
android.os.Looper.loop(Looper.java:324)
android.app.ActivityThread.main(ActivityThread.java:8140)
java.lang.reflect.Method.invoke(Native Method)
com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:559)
com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1009)

可以发现这个堆栈就是前面提到程序员的噩梦堆栈,由于发生anr之后,dump应用的线程堆栈,会有延迟,有时候dump到的堆栈就是导致ANR的Message运行结束之后,拿到的trace的日志就是这样子。

单单从堆栈已经无法找到罪魁祸首了,但是可以从HISTORY MSG可以看到这个Message运行了7002毫秒,这个就是前面am_anr中打印的Working Message,也就是导致这次ANR的罪魁祸首。

代码语言:javascript
复制
Message 0 :start=64631 delay=278ms took=7002ms repeat=0 { when=0 what=114 obj=CreateServiceData{token=android.os.BinderProxy@2d85d09 className=com.kobe.fpstest.Service packageName=com.kobe.fpstest intent=null} target=android.app.ActivityThread$H }

小结

通过简单的实践,展示了简化版的Raster和Sliver是如何发挥作用的。

六、总结

对于很多偶发ANR问题,其实都是主线程的代码,在极端的情况下,无法高效的被执行,同时手机状态又是处于比较卡顿的状态,导致dump的堆栈无法抓到导致ANR的单个或者Message的有效堆栈,从而导致很多问题基本无解。

其实Raster和Sliver的作用就是尽可能地还原发生ANR前,主线程在干什么,为什么运行那么久。

顺着这个思路,我在思考排除代码设计层面的,就是假设你的代码常规运行没有什么问题。 在极端情况下,可能运行耗时的原因可能有IO,内存,CPU调度,如果尽可能还原发生ANR问题前,主线程的IO,内存,CPU调度的状态,以及影响他们的其他进程线程,那样子很多ANR问题就可以迎刃而解。

我第一个想到的就是抓Perfetto Trace,可惜抓trace会影响一定性能,不能一直抓,等到ANR发生了再抓,又有可能来不及,除非可以预判即将发生ANR,然后提前抓Trace,就可以解决这个问题。

尾巴

本文是在研究字节的文章以后,加上自己一些小实践以后的感悟,要彻底消灭ANR,目前还没有一个非常牛逼手段。由于字节的Raster和Sliver并没有开源,很多信息是我从文章里面推测出来的,如果有理解不到位的点,请大家多多指正。

希望我的文章对你破局ANR问题有一些启发的意义。

本文参与 腾讯云自媒体同步曝光计划,分享自作者个人站点/博客。
原始发表:2022-05-14,如有侵权请联系 cloudcommunity@tencent.com 删除

本文分享自 作者个人站点/博客 前往查看

如有侵权,请联系 cloudcommunity@tencent.com 删除。

本文参与 腾讯云自媒体同步曝光计划  ,欢迎热爱写作的你一起参与!

评论
登录后参与评论
0 条评论
热度
最新
推荐阅读
目录
  • 前言
  • 一、工程师的噩梦
  • 二、字节整治ANR法宝
    • 2.1 Raster
      • 2.2 Sliver
        • 小结
        • 三、制造一个ANR现场
        • 四、简化版Raster和Sliver设计
          • 4.1 简化版Raster
            • 4.2 简化版的Sliver
              • 4.3 触发的时间
              • 五、实践
                • 5.1 am_anr时候触发
                  • 5.2 ANR in时候触发
                    • 小结
                    • 六、总结
                    • 尾巴
                    领券
                    问题归档专栏文章快讯文章归档关键词归档开发者手册归档开发者手册 Section 归档