1. 背景
项目的开发过程中,经常遇到app的卡顿问题,显示问题,在没有现场的情况下,往往需要借助events log定位分析问题。本文从实际项目出发,详细介绍了events log的来龙去脉,以及遇到的activity stop timeout的原理分析。
07-14 14:15:22.199849 943 4111 I wm_stop_activity: [0,48692746,com.android.live.audiobox/com.android.liveaudiobox.home.HomeActivity]
07-14 14:15:33.206605 943 1100 W ActivityTaskManager: Activity stop timeout for ActivityRecord{2e6fe0a u0 com.android.live.audiobox/com.android.liveaudiobox.home.HomeActivity t346}
07-14 14:15:33.206741 943 1100 I ActivityTaskManager: Activity reported stop, but no longer stopping: ActivityRecord{2e6fe0a u0 com.android.live.audiobox/com.android.liveaudiobox.home.HomeActivity t346}
2. 问题分析
遇到上面的log,相信大家会有两点疑问:
- wm_stop_activity 什么意思?是app 已经onStop了吗?还是马上呼叫app执行onStop方法?
- activity stop还有timeout,timeout时长是多少呢?
疑问一
通过关键字wm_stop_activity 整个源码搜索,搜索结果如下:
上面的搜索结果非常奇怪,怎么是logtags的文件,不是java文件呢?
继续搜索终于在下面的路径下搜到了java文件:
android\out\soong.intermediates\frameworks\base\services\core\services.core.unboosted\android_common\gen\logtags\frameworks\base\services\core\java\com\android\server\wm\EventLogTags.java
public static void writeWmStopActivity(int user, int token, String componentName) {
android.util.EventLog.writeEvent(WM_STOP_ACTIVITY, user, token, componentName);
}
从文件路径可以看出,这个是编译脚本编译出来的。
/**
* Request to move an activity to stopped state.
* @hide
*/
public class StopActivityItem extends ActivityLifecycleItem {
private static final String TAG = "StopActivityItem";
private int mConfigChanges;
@Override
public void execute(ClientTransactionHandler client, IBinder token,
PendingTransactionActions pendingActions) {
Trace.traceBegin(TRACE_TAG_ACTIVITY_MANAGER, "activityStop");
client.handleStopActivity(token, mConfigChanges, pendingActions,
true /* finalStateRequest */, "STOP_ACTIVITY_ITEM");
Trace.traceEnd(TRACE_TAG_ACTIVITY_MANAGER);
}
private final Runnable mStopTimeoutRunnable = new Runnable() {
@Override
public void run() {
synchronized (mAtmService.mGlobalLock) {
Slog.w(TAG, "Activity stop timeout for " + ActivityRecord.this);
if (isInHistory()) {
activityStopped(
null /*icicle*/, null /*persistentState*/, null /*description*/);
}
}
}
};
到这里,疑问一应该比较清楚了,wm_stop_activity 是AMS 打印出来的,这个event log之后,app马上会执行onStop方法,且framework会为stop开启一个11s的timeout计时,如果11s的时间内都没有成功执行onStop方法,会执行activityStopped方法。
疑问二
从google的注释来看,这个timeout 11s是非常合理的,考虑到了app 10s的ANR的情况,多出1s是为了让系统有充足的时间dump anr信息。
// How long we wait for the activity to tell us it has stopped before
// giving up. This is a good amount of time because we really need this
// from the application in order to get its saved state. Once the stop
// is complete we may start destroying client resources triggering
// crashes if the UI thread was hung. We put this timeout one second behind
// the ANR timeout so these situations will generate ANR instead of
// Surface lost or other errors.
private static final int STOP_TIMEOUT = 11 * 1000;