Android 8.1.0 调试笔记 - 处理 “Duplicate finish request for ActivityRecord”

        在测试工具 app 中进行某一项测试时,界面突然挂了。分析日志,发现日志中 crash 的地方是输入法?喵喵喵!?

        总的来说,报错日志像下面这样:

//log...

01-25 18:19:23.050 W/ActivityManagerService(  442): Duplicate finish request for ActivityRecord{62dbc14 u0 com.xxxxx.xxxxx.xxxxxfactorytest/com.xxxxx.xxxxx.quicktest.view.cameratest.CameraPreviewActivity t6 f}

01-25 18:19:23.086 W/InputMethodManagerService(  442): Focus gain on non-focused client com.android.internal.view.IInputMethodClient$Stub$Proxy@2f26bf84 (uid=10030 pid=17034)

//log...

01-25 18:19:23.387 W/ActivityManagerService(  442): Duplicate finish request for ActivityRecord{894bc62 u0 com.xxxxx.xxxxx.xxxxxfactorytest/com.xxxxx.xxxxx.quicktest.view.cameratest.CameraPreviewActivity t6 f}

01-25 18:19:23.431 W/InputMethodManagerService(  442): Focus gain on non-focused client com.android.internal.view.IInputMethodClient$Stub$Proxy@2f26bf84 (uid=10030 pid=17034)

//log...

01-25 19:09:39.187 E/libc++abi(17034): (null)

--------- beginning of crash

01-25 19:09:39.187 F/libc    (17034): Fatal signal 6 (SIGABRT), code -6 in tid 21041 (aierfactorytest)

01-25 19:09:39.187 I/libc    (17034): Suppressing debuggerd output because prctl(PR_GET_DUMPABLE)==0

//log...

//log...

01-25 19:09:39.568 D/AndroidRuntime(21065): Shutting down VM

01-25 19:09:39.572 D/CrashHandler(21065): crash file:/mnt/sdcard/factorytest/crash2013_01_25_19_09:39.log

01-25 19:09:39.572 W/System.err(21065): java.io.IOException: open failed: EINVAL (Invalid argument)

01-25 19:09:39.572 W/System.err(21065): 	at java.io.File.createNewFile(File.java:941)

01-25 19:09:39.572 W/System.err(21065): 	at com.xxxxx.xxxxx.xxxxxfactorytest.CrashHandler.writeToSDcard(CrashHandler.java:86)

01-25 19:09:39.572 W/System.err(21065): 	at com.xxxxx.xxxxx.xxxxxfactorytest.CrashHandler.uncaughtException(CrashHandler.java:53)

01-25 19:09:39.572 W/System.err(21065): 	at java.lang.ThreadGroup.uncaughtException(ThreadGroup.java:693)

01-25 19:09:39.572 W/System.err(21065): 	at java.lang.ThreadGroup.uncaughtException(ThreadGroup.java:690)

01-25 19:09:39.572 W/System.err(21065): Caused by: android.system.ErrnoException: open failed: EINVAL (Invalid argument)

01-25 19:09:39.573 W/System.err(21065): 	at libcore.io.Posix.open(Native Method)

01-25 19:09:39.573 W/System.err(21065): 	at libcore.io.BlockGuardOs.open(BlockGuardOs.java:186)

01-25 19:09:39.573 W/System.err(21065): 	at java.io.File.createNewFile(File.java:934)

01-25 19:09:39.573 W/System.err(21065): 	... 4 more

01-25 19:09:39.573 W/System.err(21065): java.lang.RuntimeException: Unable to start activity ComponentInfo{com.xxxxx.xxxxx.xxxxxfactorytest/com.xxxxx.xxxxx.xxxxxfactorytest.view.burningtest.BurningTestActivity}: android.content.res.Resources$NotFoundException: Resource ID #0x0

01-25 19:09:39.573 W/System.err(21065): 	at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2345)

01-25 19:09:39.573 W/System.err(21065): 	at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2407)

01-25 19:09:39.573 W/System.err(21065): 	at android.app.ActivityThread.access$800(ActivityThread.java:151)

01-25 19:09:39.573 W/System.err(21065): 	at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1319)

01-25 19:09:39.573 W/System.err(21065): 	at android.os.Handler.dispatchMessage(Handler.java:102)

01-25 19:09:39.573 W/System.err(21065): 	at android.os.Looper.loop(Looper.java:135)

01-25 19:09:39.573 W/System.err(21065): 	at android.app.ActivityThread.main(ActivityThread.java:5280)

01-25 19:09:39.573 W/System.err(21065): 	at java.lang.reflect.Method.invoke(Native Method)

01-25 19:09:39.573 W/System.err(21065): 	at java.lang.reflect.Method.invoke(Method.java:372)

01-25 19:09:39.573 W/System.err(21065): 	at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:963)

01-25 19:09:39.573 W/System.err(21065): 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:758)

01-25 19:09:39.573 W/System.err(21065): Caused by: android.content.res.Resources$NotFoundException: Resource ID #0x0

01-25 19:09:39.573 W/System.err(21065): 	at android.content.res.Resources.getValue(Resources.java:1283)

01-25 19:09:39.573 W/System.err(21065): 	at android.content.res.Resources.loadXmlResourceParser(Resources.java:2667)

01-25 19:09:39.573 W/System.err(21065): 	at android.content.res.Resources.getLayout(Resources.java:1099)

01-25 19:09:39.574 W/System.err(21065): 	at android.view.LayoutInflater.inflate(LayoutInflater.java:412)

01-25 19:09:39.574 W/System.err(21065): 	at android.view.LayoutInflater.inflate(LayoutInflater.java:365)

01-25 19:09:39.574 W/System.err(21065): 	at android.support.v7.app.AppCompatDelegateImplV7.setContentView(AppCompatDelegateImplV7.java:249)

01-25 19:09:39.574 W/System.err(21065): 	at android.support.v7.app.AppCompatActivity.setContentView(AppCompatActivity.java:106)

01-25 19:09:39.574 W/System.err(21065): 	at com.xxxxx.xxxxx.xxxxxfactorytest.view.base.BaseActivity.onCreate(BaseActivity.java:57)

01-25 19:09:39.574 W/System.err(21065): 	at android.app.Activity.performCreate(Activity.java:6222)

01-25 19:09:39.574 W/System.err(21065): 	at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1106)

01-25 19:09:39.574 W/System.err(21065): 	at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2295)

01-25 19:09:39.574 W/System.err(21065): 	... 10 more

01-25 19:09:39.574 E/AndroidRuntime(21065): FATAL EXCEPTION: main

01-25 19:09:39.574 E/AndroidRuntime(21065): Process: com.xxxxx.xxxxx.xxxxxfactorytest, PID: 21065

01-25 19:09:39.574 E/AndroidRuntime(21065): java.lang.RuntimeException: Unable to start activity ComponentInfo{com.xxxxx.xxxxx.xxxxxfactorytest/com.xxxxx.xxxxx.xxxxxfactorytest.view.burningtest.BurningTestActivity}: android.content.res.Resources$NotFoundException: Resource ID #0x0

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2345)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2407)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at android.app.ActivityThread.access$800(ActivityThread.java:151)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1319)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at android.os.Handler.dispatchMessage(Handler.java:102)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at android.os.Looper.loop(Looper.java:135)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at android.app.ActivityThread.main(ActivityThread.java:5280)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at java.lang.reflect.Method.invoke(Native Method)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at java.lang.reflect.Method.invoke(Method.java:372)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:963)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:758)

01-25 19:09:39.574 E/AndroidRuntime(21065): Caused by: android.content.res.Resources$NotFoundException: Resource ID #0x0

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at android.content.res.Resources.getValue(Resources.java:1283)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at android.content.res.Resources.loadXmlResourceParser(Resources.java:2667)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at android.content.res.Resources.getLayout(Resources.java:1099)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at android.view.LayoutInflater.inflate(LayoutInflater.java:412)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at android.view.LayoutInflater.inflate(LayoutInflater.java:365)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at android.support.v7.app.AppCompatDelegateImplV7.setContentView(AppCompatDelegateImplV7.java:249)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at android.support.v7.app.AppCompatActivity.setContentView(AppCompatActivity.java:106)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at com.xxxxx.xxxxx.xxxxxfactorytest.view.base.BaseActivity.onCreate(BaseActivity.java:57)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at android.app.Activity.performCreate(Activity.java:6222)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1106)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2295)

01-25 19:09:39.574 E/AndroidRuntime(21065): 	... 10 more

01-25 19:09:39.577 W/ActivityManagerService(  442):   Force finishing activity 1 com.xxxxx.xxxxx.xxxxxfactorytest/.view.burningtest.BurningTestActivity

        为什么会打印 Duplicate finish request for ActivityRecord{ ...CameraPreviewActivity t6 f}呢?

        为什么会打印 Focus gain on non-focused client  IInputMethodClient (uid=10030 pid=17034) 呢?

        查找源码发现:

        "Duplicate finish..."  之所以会被打印出来,是因为回调到了系统服务 ActivityStack.java 的 finishActivityLocked()方法:

    /**
     * @return Returns true if this activity has been removed from the history
     * list, or false if it is still in the list and will be removed later.
     */
    final boolean finishActivityLocked(ActivityRecord r, int resultCode, Intent resultData,
            String reason, boolean oomAdj) {
        if (r.finishing) {
            Slog.w(TAG, "Duplicate finish request for " + r);
            return false;
        }


     //code......

        return false;
    }

 

        "Focus gain on non-focused client" 之所以会被打印出来,是因为回调到了系统服务 InputMethodManagerService.java 的 windowGainedFocus()  方法:

    @Override
    public InputBindResult windowGainedFocus(IInputMethodClient client, IBinder windowToken,
            int controlFlags, int softInputMode, int windowFlags,
            EditorInfo attribute, IInputContext inputContext) {

        // code...

        try {
            synchronized (mMethodMap) {

                //code...

                try {
                    if (!mIWindowManager.inputMethodClientHasFocus(cs.client)) {
                        // Check with the window manager to make sure this client actually
                        // has a window with focus.  If not, reject.  This is thread safe
                        // because if the focus changes some time before or after, the
                        // next client receiving focus that has any interest in input will
                        // be calling through here after that change happens.
                        Slog.w(TAG, "Focus gain on non-focused client " + cs.client
                                + " (uid=" + cs.uid + " pid=" + cs.pid + ")");
                        return null;
                    }
                } catch (RemoteException e) {


                }

          //code...
                }

            }
        } finally {
            Binder.restoreCallingIdentity(ident);
        }

        return res;
    }

        所以分析,这里应该就是代码中多次主动调用了 CameraPreviewActivity 界面的 finish() 方法,关键是在调用 finish() 方法之前,并未对当前界面的状态做判断,最后导致当前窗口获取到焦点,系统回调到了系统输入法服务 InputMethodManagerService 的 windowGainedFocus() 方法。 代码中多次错误调用界面的 finish() 方法,最终导致在 so 库中报错,应用挂掉。

        解决方法就是在finish()前通过isFinishing()判断是否已经finish 。

        吐槽一个地方,在定位源码中日志输出 " Duplicate finish request ... " 的时候,差点没憋死我,因为日志的 TAG 命名显示是 "ActivityManagerService" ,那按照一般人的理解,这个日志应该是在 ActivityManagerService.java 中打印出来的,可是在ActivityManagerService.java 中查找了半天,这个java 文件没有打印这句话,最后终于在热心网友的博客中发现,这行日志是在 ActivityStack.java 中打印出来的,这个类导包:import static com.android.server.am.ActivityManagerService.TAG;WTF!?

 

【参考链接】

https://www.jianshu.com/p/8cd648845705

https://blog.csdn.net/weixin_33910759/article/details/91392658

https://blog.csdn.net/kris_fei/article/details/76582585

 

 

 

  • 0
    点赞
  • 1
    收藏
    觉得还不错? 一键收藏
  • 0
    评论
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值