在测试工具 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