记录处理Android 较为诡异的问题,Activity#onResume()发生IllegalArgumentException 异常。
1.Activity#onResume()异常
最近在处理Bugly上的量级较大的问题,发现有一个较为奇怪的问题,发生在ActivityThread#performResumeActivity(),即Activity#onResume()
方法报错。
先来看下,设备信息:
设备信息 | ROM | CPU架构 | android版本 |
---|---|---|---|
MP1603 | Meitu/M8 | arm64-v8a | Android 7.1.1,level 25 |
Bugly上报的异常信息:
Caused by:
java.lang.IllegalArgumentException:
android.os.Parcel.readException(Parcel.java:1688)
android.os.Parcel.readException(Parcel.java:1637)
android.app.ActivityManagerProxy.isTopOfTask(ActivityManagerNative.java:5505)
android.app.Activity.isTopOfTask(Activity.java:6008)
android.app.Activity.onResume(Activity.java:1266)
org.appplay.lib.GameBaseActivity.onResume(GameBaseActivity.java)
org.appplay.lib.AppPlayBaseActivity.onResume(AppPlayBaseActivity.java)
com.xxxtech.xxx.MiniWorldActivity.onResume(xxxWorldActivity.java)
android.app.Instrumentation.callActivityOnResume(Instrumentation.java:1269)
android.app.Activity.performResume(Activity.java:6813)
android.app.ActivityThread.performResumeActivity(ActivityThread.java:3407)
android.app.ActivityThread.handleResumeActivity(ActivityThread.java:3470)
android.app.ActivityThread$H.handleMessage(ActivityThread.java:1528)
android.os.Handler.dispatchMessage(Handler.java:102)
android.os.Looper.loop(Looper.java:154)
android.app.ActivityThread.main(ActivityThread.java:6121)
java.lang.reflect.Method.invoke(Native Method)
com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:905)
com.android.internal.os.ZygoteInit.main(ZygoteInit.java:795)
从异常信息上看不到有啥有效信息,因此,考虑从源码入手看下这个流程走向。
2.源码分析
因设备是在android 7.1 中发生异常,因此查看android 7.1的源码进行分析。
先从Activity#onresume()
的源码,开始查看:
protected void onResume() {
if (DEBUG_LIFECYCLE) Slog.v(TAG, "onResume " + this);
getApplication().dispatchActivityResumed(this);
mActivityTransitionState.onResume(this, isTopOfTask());
mCalled = true;
}
接下来,继续看Activity# isTopOfTask()
中的源码:
private boolean isTopOfTask() {
//...........
try {
return ActivityManagerNative.getDefault().isTopOfTask(getActivityToken());
} catch (RemoteException e) {
return false;
}
}
接下来,查看下ActivityManagerNative#isTopOfTask()
中的源码:
public boolean isTopOfTask(IBinder token) throws RemoteException {
Parcel data = Parcel.obtain();
Parcel reply = Parcel.obtain();
data.writeInterfaceToken(IActivityManager.descriptor);
data.writeStrongBinder(token);
mRemote.transact(IS_TOP_OF_TASK_TRANSACTION, data, reply, 0);
reply.readException();
boolean res = reply.readInt() == 1;
data.recycle();
reply.recycle();
return res;
}
接下来,会从app进程走到system进程中,查看下ActivityManagerService#isTopOfTask()
源码中:
@Override
public boolean isTopOfTask(IBinder token) {
synchronized (this) {
ActivityRecord r = ActivityRecord.isInStackLocked(token);
if (r == null) {
throw new IllegalArgumentException();
}
return r.task.getTopActivity() == r;
}
}
从上面源码可知,当ativity的IBinder对象在ams 中没有记录时,就会抛出IllegalArgumentException异常。
猜测:Activity发生了某种异常状态,导致ams 将Acitivity从Record记录中移除了。在某个时机下,app 又执行了Activity 恢复onResume状态,因此导致了IllegalArgumentException异常。
3.可行性不高的方案
通过谷歌搜索,其他小伙伴也遇到了类似的问题。
3.1 通过捕捉异常,反射修改 mCalled,继续执行逻辑
先来看下谷歌上讨论该问题,其中有人提出一种方案:可能存在不可测的风险
public void onResume() {
try {
super.onResume();
} catch(IllegalStateException e) {
try {
Field f = Activity.class.getDeclaredField("mCalled");
f.setAccessible(true);
f.set(this, true);
} catch (IllegalArgumentException | IllegalAccessException | NoSuchFieldException e1) {
}
}
....
}
更多详情,请阅读谷歌Activity#onResume异常讨论。
3.2 通过Hook , 捕捉异常,继续执行逻辑:
也有网友提出,从hook ActivityManagerNative 入手,捕捉ams 抛出的异常:可能存在不可测的风险
private class IActivityManagerProxy(private val instance: Any): InvocationHandler {
override fun invoke(proxy: Any?, method: Method, args: Array<out Any>?): Any? {
Logger.i(TAG, "invoke: ${method.name}")
if (method.name == "isTopOfTask") {
return try {
method.invoke(instance, *(args ?: emptyArray())) as Boolean
} catch (e: Exception) {
// 这里就可以将我们最初要解决的IllegalArgumentException给try-catch住,
// 这样就达到了我们的目的了。
Logger.w(TAG, "isTopOfTask invoke exception: $e")
false
}
}
return method.invoke(instance, *(args ?: emptyArray()))
}
}
更多详情,请阅读Hook 处理 Activity#onResume ()。
3.3 捕捉异常,根据异常具体分析:
这个方案是借鉴了ActivityThread#performResumeActivity():
public final ActivityClientRecord performResumeActivity(IBinder token,
boolean clearHide, String reason) {
//........
try {
r.activity.performResume();
} catch (Exception e) {
if (!mInstrumentation.onException(r.activity, e)) {
throw new RuntimeException(
"Unable to resume activity "
+ r.intent.getComponent().toShortString()
+ ": " + e.toString(), e);
}
}
return r;
}
根据官方的思路,提出一种可行方案:为Acitivity注册 Instrumentation ,通过onException来获取到异常信息和调用栈。若是有Thread#setUncaughtExceptionHandler
也可以上报该异常详细情况。阅读更多详细信息
归根结底,来时需要搞清楚在 activity stop timeout 这段时间,借助log 分析 activity发生了哪些变化。
4.借助Log 信息分析 解决
因项目中集成了Bugly ,bugly会捕捉当时的log信息,省略获取重现的log 过程。
在Bugly官网中发现一段有用的log 信息:
6207-27 10:02:39.243 2935 3420 E CrashReport-Native: not open trace switch JAR_JNI_VERSION is 1 or dump type is sigquit
6307-27 10:02:40.099 2935 3224 E CrashReport: main thread blocked,now begin to upload anr stack
6407-27 10:02:40.251 2935 3224 E CrashReport: #++++++++++Record By Bugly++++++++++#
6507-27 10:02:40.251 2935 3224 E CrashReport: # You can use Bugly(http:\\bugly.qq.com) to get more Crash Detail!
6607-27 10:02:40.251 2935 3224 E CrashReport: # PKG NAME: com.tencent.tmgp.xxxtech.xxxworld
6707-27 10:02:40.251 2935 3224 E CrashReport: # APP VER: 1.15.0
6807-27 10:02:40.251 2935 3224 E CrashReport: # SDK VER: 3.4.4-3.9.2
6907-27 10:02:40.252 2935 3224 E CrashReport: # LAUNCH TIME: 2022-07-27 10:02:29
7007-27 10:02:40.252 2935 3224 E CrashReport: # CRASH TYPE: ANR
7107-27 10:02:40.252 2935 3224 E CrashReport: # CRASH TIME: 2022-07-27 10:02:40
7207-27 10:02:40.252 2935 3224 E CrashReport: # CRASH PROCESS: null
7307-27 10:02:40.253 2935 3224 E CrashReport: # CRASH THREAD: main
7407-27 10:02:40.253 2935 3224 E CrashReport: # REPORT ID: 245c625f-943b-4c04-9bb1-d5943aa4cae1
7507-27 10:02:40.253 2935 3224 E CrashReport: # CRASH DEVICE: Z1026G ROOTED
7607-27 10:02:40.253 2935 3224 E CrashReport: # RUNTIME AVAIL RAM:1076092928 ROM:3734093824 SD:3734093824
7707-27 10:02:40.253 2935 3224 E CrashReport: # RUNTIME TOTAL RAM:2070941696 ROM:27512537088 SD:27512537088
7807-27 10:02:40.253 2935 3224 E CrashReport: # EXCEPTION ANR MESSAGE:
7907-27 10:02:40.253 2935 3224 E CrashReport: null
8007-27 10:02:40.253 2935 3224 E CrashReport: # CRASH STACK:
8107-27 10:02:40.253 2935 3224 E CrashReport: java.io.UnixFileSystem.getBooleanAttributes0(Native Method)
8207-27 10:02:40.253 2935 3224 E CrashReport: java.io.UnixFileSystem.getBooleanAttributes(UnixFileSystem.java:242)
8307-27 10:02:40.253 2935 3224 E CrashReport: java.io.File.isDirectory(File.java:804)
8407-27 10:02:40.253 2935 3224 E CrashReport: org.appplay.lib.FileUtils.getSize(FileUtils.java)
8507-27 10:02:40.253 2935 3224 E CrashReport: org.appplay.lib.FileUtils.getSize(FileUtils.java)
8607-27 10:02:40.253 2935 3224 E CrashReport: org.appplay.lib.FileUtils.getSize(FileUtils.java)
8707-27 10:02:40.253 2935 3224 E CrashReport: org.appplay.lib.FileUtils.getSize(FileUtils.java)
8807-27 10:02:40.253 2935 3224 E CrashReport: org.appplay.lib.FileUtils.getSize(FileUtils.java)
8907-27 10:02:40.253 2935 3224 E CrashReport: org.appplay.lib.GameBaseActivity.DoSetPackageName(GameBaseActivity.java)
9007-27 10:02:40.253 2935 3224 E CrashReport: org.appplay.lib.AppPlayBaseActivity.Show_GLView(AppPlayBaseActivity.java)
9107-27 10:02:40.253 2935 3224 E CrashReport: com.minitech.miniworld.MiniWorldActivity.onActivityResult(MiniWorldActivity.java)
9207-27 10:02:40.253 2935 3224 E CrashReport: android.app.Activity.dispatchActivityResult(Activity.java:6962)
9307-27 10:02:40.253 2935 3224 E CrashReport: android.app.ActivityThread.deliverResults(ActivityThread.java:4086)
9407-27 10:02:40.253 2935 3224 E CrashReport: android.app.ActivityThread.handleSendResult(ActivityThread.java:4133)
9507-27 10:02:40.253 2935 3224 E CrashReport: android.app.ActivityThread.-wrap20(ActivityThread.java)
9607-27 10:02:40.253 2935 3224 E CrashReport: android.app.ActivityThread$H.handleMessage(ActivityThread.java:1534)
9707-27 10:02:40.253 2935 3224 E CrashReport: android.os.Handler.dispatchMessage(Handler.java:102)
9807-27 10:02:40.253 2935 3224 E CrashReport: android.os.Looper.loop(Looper.java:154)
9907-27 10:02:40.253 2935 3224 E CrashReport: android.app.ActivityThread.main(ActivityThread.java:6121)
10007-27 10:02:40.253 2935 3224 E CrashReport: java.lang.reflect.Method.invoke(Native Method)
10107-27 10:02:40.253 2935 3224 E CrashReport: com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:905)
10207-27 10:02:40.253 2935 3224 E CrashReport: com.android.internal.os.ZygoteInit.main(ZygoteInit.java:795)
10307-27 10:02:40.253 2935 3224 E CrashReport: #++++++++++++++++++++++++++++++++++++++++++#
//.......
16707-27 10:03:19.180 2935 2935 D AudioTrack: Client defaulted notificationFrames to 860 for frameCount 2580
16807-27 10:03:20.481 2935 2935 E libEGL : call to OpenGL ES API with no current context (logged once per thread)
16907-27 10:03:22.503 2935 2935 D AudioTrack: Client defaulted notificationFrames to 860 for frameCount 2580
17007-27 10:03:22.771 2935 2935 D AndroidRuntime: Shutting down VM
17107-27 10:03:22.958 2935 3883 E CrashReport: Java Crash Happen cause by main(1)
从上面的日志可知,在从其他应用跳转回到app时,发生了anr事件。 有人会好奇问,这个和onResume()发生异常有啥子关系呢???
探究下从其他应用跳转回app,先执行onResume 还是onActivityResult()???
继续查看下,在Activity的onActivityResult() 的源码:
/**
* You will receive this call immediately before onResume() when your activity is re-starting.
*/
protected void onActivityResult(int requestCode, int resultCode, Intent data) {
}
从上面可见onActivityResult() 在onResume() 之前执行。
因此,app 在onResume 之前,发生了anr 异常情况,导致了ams 从record 记录中移除该Activity的Ibinder 信息。当Activity执行onResume()就抛出IllegalArgumentException异常。
解决方案:也是处理anr 问题。当然,每个app 遇到的情况都不一样,需要对症下药,根据实际的日志信息来处理异常,才可以避免Activity#onResume 问题。
除此之外,同个报错类型中,其他上报日志中也找到类似anr的报错,也验证了上面分析猜想:
12807-26 22:01:10.797 13951 14336 E CrashReport-Native: not open trace switch JAR_JNI_VERSION is 1 or dump type is sigquit
12907-26 22:01:12.419 13951 14182 E CrashReport: main thread blocked,now begin to upload anr stack
13007-26 22:01:12.644 13951 14182 E CrashReport: #++++++++++Record By Bugly++++++++++#
13107-26 22:01:12.644 13951 14182 E CrashReport: # You can use Bugly(http:\\bugly.qq.com) to get more Crash Detail!
13207-26 22:01:12.644 13951 14182 E CrashReport: # PKG NAME: com.tencent.tmgp.xxxx.xxxxworld
13307-26 22:01:12.644 13951 14182 E CrashReport: # APP VER: 1.13.0
13407-26 22:01:12.644 13951 14182 E CrashReport: # SDK VER: 3.4.4-3.9.2
13507-26 22:01:12.645 13951 14182 E CrashReport: # LAUNCH TIME: 2022-07-26 22:00:54
13607-26 22:01:12.646 13951 14182 E CrashReport: # CRASH TYPE: ANR
13707-26 22:01:12.646 13951 14182 E CrashReport: # CRASH TIME: 2022-07-26 22:01:12
13807-26 22:01:12.646 13951 14182 E CrashReport: # CRASH PROCESS: null
13907-26 22:01:12.646 13951 14182 E CrashReport: # CRASH THREAD: main
14007-26 22:01:12.646 13951 14182 E CrashReport: # REPORT ID: 97a727da-ae7e-4f79-a9e3-79a5a259ab6a
14107-26 22:01:12.646 13951 14182 E CrashReport: # CRASH DEVICE: M654 UNROOT
14207-26 22:01:12.647 13951 14182 E CrashReport: # RUNTIME AVAIL RAM:1354084352 ROM:2202357760 SD:2202357760
14307-26 22:01:12.647 13951 14182 E CrashReport: # RUNTIME TOTAL RAM:1979883520 ROM:11595116544 SD:11595116544
14407-26 22:01:12.647 13951 14182 E CrashReport: # EXCEPTION ANR MESSAGE:
14507-26 22:01:12.647 13951 14182 E CrashReport: null
14607-26 22:01:12.647 13951 14182 E CrashReport: # CRASH STACK:
14707-26 22:01:12.647 13951 14182 E CrashReport: org.appplay.lib.AppPlayNatives.NativeInit(Native Method)
14807-26 22:01:12.647 13951 14182 E CrashReport: org.appplay.lib.AppPlayNatives.nativeInit(AppPlayNatives.java)
14907-26 22:01:12.647 13951 14182 E CrashReport: org.appplay.lib.AppPlayBaseActivity.Show_GLView(AppPlayBaseActivity.java)
15007-26 22:01:12.647 13951 14182 E CrashReport: com.xxxtech.miniworld.xxxWorldActivity.onActivityResult(xxxWorldActivity.java)
15107-26 22:01:12.647 13951 14182 E CrashReport: android.app.Activity.dispatchActivityResult(Activity.java:7001)
15207-26 22:01:12.647 13951 14182 E CrashReport: android.app.ActivityThread.deliverResults(ActivityThread.java:4147)
15307-26 22:01:12.647 13951 14182 E CrashReport: android.app.ActivityThread.handleSendResult(ActivityThread.java:4194)
15407-26 22:01:12.647 13951 14182 E CrashReport: android.app.ActivityThread.-wrap20(ActivityThread.java)
15507-26 22:01:12.647 13951 14182 E CrashReport: android.app.ActivityThread$H.handleMessage(ActivityThread.java:1543)
15607-26 22:01:12.647 13951 14182 E CrashReport: android.os.Handler.dispatchMessage(Handler.java:102)
15707-26 22:01:12.647 13951 14182 E CrashReport: android.os.Looper.loop(Looper.java:154)
15807-26 22:01:12.647 13951 14182 E CrashReport: android.app.ActivityThread.main(ActivityThread.java:6217)
15907-26 22:01:12.647 13951 14182 E CrashReport: java.lang.reflect.Method.invoke(Native Method)
16007-26 22:01:12.647 13951 14182 E CrashReport: com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:885)
16107-26 22:01:12.647 13951 14182 E CrashReport: com.android.internal.os.ZygoteInit.main(ZygoteInit.java:775)
16207-26 22:01:12.647 13951 14182 E CrashReport: #++++++++++++++++++++++++++++++++++++++++++#