快速点击StartActivity引发的误会

问题来源





在A 跳到 B ,再跳到C的过程中,一定条件下发送广播,需要把B关掉,达到的效果就是 C直接返回A。


但是现在出现一个Bug就是C返回的时候,还是B。当时没有打印onCreate的日志,只发现B在前面finish了,居然又在后面onResume了,这显然违反科学。当时想就算B启动了多个,B也都在onCreate的时候注册了广播,都应该可以收到广播的。后面怀疑是手滑不小心点击了2次,或是系统突然响应过慢,点击了多次,造成创建了多个实例,所以我直接通过for循环快速模拟这种情况。

问题分析

  • 模拟复现问题
    1
    2
    3
    for (int i = 0; i < 4; i++) {
    startActivity(new Intent(MainActivity.this, Main2Activity.class));
    }

首先查看 activity栈

  • 通过db shell dumpsys activity activities 查看 activity栈的详细信息
  • 过滤了我们只关心的信息
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
* Hist #4: ActivityRecord{6a9b44e u0 com.test/.Main2Activity t36}
state=RESUMED stopped=false delayedResume=false finishing=false
* Hist #3: ActivityRecord{d603f13 u0 com.test/.Main2Activity t36}
state=INITIALIZING stopped=false delayedResume=false finishing=false
* Hist #2: ActivityRecord{ec9aee4 u0 com.test/.Main2Activity t36}
state=INITIALIZING stopped=false delayedResume=false finishing=false
* Hist #1: ActivityRecord{aea6311 u0 com.test/.Main2Activity t36}
state=INITIALIZING stopped=false delayedResume=false finishing=false
* Hist #0: ActivityRecord{ff269a8 u0 com.test/.MainActivity t36}
state=STOPPED stopped=true delayedResume=false finishing=false
Running activities (most recent first):
TaskRecord{561d198 #36 A=com.test U=0 StackId=11 sz=5}
Run #1: ActivityRecord{6a9b44e u0 com.test/.Main2Activity t36}
Run #0: ActivityRecord{ff269a8 u0 com.test/.MainActivity t36}

mResumedActivity: ActivityRecord{6a9b44e u0 com.test/.Main2Activity t36}

state=INITIALIZING ??


我们可以看到创建了4个ActivityRecord,这个是符合预期的,前面的3个ActivityRecord状态还是INITIALIZING,就最后一个ActivityRecord走到了RESUMED。发现在这种情况下面,点击返回的时候,state=INITIALIZING 的Activity才走了onCreate。

疑惑? 难道前面的 ActivityRecord 不应该都是 state=STOPPED 吗?

  • 怀疑点,所有的Activity的生命周期方法都是AMS来回调的,都会在我们的主线程消息里面处理
  • 是不是AMS反应太慢?反正就是AMS的回到消息没有发过来?
  • 消息发过来了,我们还没有处理


基于上面的假设我们,我们可以dump一下消息

  • dump message 查看主线程的的Looper里的MessageQueue里面的持有的消息
1
2
3
4
5
6
7
8
9
 
for (int i = 0; i < 4; i++) {
Log.i(TAG, "startActivity: click -------------------");
startActivity(new Intent(MainActivity.this, Main2Activity.class));
dump();
}
public static void dump() {
Looper.getMainLooper().dump(new LogPrinter(Log.DEBUG, TAG), "PREFIX");
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41

// 第一次立马点击的时候,就收到了一个 ClientTransaction 消息
3.609 I/MainActivity: startActivity: click -------------------
3.670 Looper (main, tid 2) {833b991}
3.670 Message 0: { when=-67ms callback=android.view.View$UnsetPressedState target=android.view.ViewRootImpl$ViewRootHandler }
3.671 Message 1: { when=-29ms what=159 obj=android.app.servertransaction.ClientTransaction@efd342 target=android.app.ActivityThread$H }
3.671 (Total messages: 2, polling=false, quitting=false)


//第二次点击的时候,并没有收到消息,可以看到消息没有变化
3.671 I/MainActivity: startActivity: click -------------------
3.721 Looper (main, tid 2) {833b991}
3.721 Message 0: { when=-118ms callback=android.view.View$UnsetPressedState target=android.view.ViewRootImpl$ViewRootHandler }
3.721 Message 1: { when=-80ms what=159 obj=android.app.servertransaction.ClientTransaction@efd342 target=android.app.ActivityThread$H }
3.721 (Total messages: 2, polling=false, quitting=false)


//第三次点击的时候,并没有收到消息,可以看到消息没有变化
3.721 I/MainActivity: startActivity: click -------------------
3.760 Looper (main, tid 2) {833b991}
3.760 Message 0: { when=-157ms callback=android.view.View$UnsetPressedState target=android.view.ViewRootImpl$ViewRootHandler }
3.761 Message 1: { when=-119ms what=159 obj=android.app.servertransaction.ClientTransaction@efd342 target=android.app.ActivityThread$H }
3.761 (Total messages: 2, polling=false, quitting=false)


//第四次点击的时候,并没有收到消息,可以看到消息没有变化
3.761 I/MainActivity: startActivity: click -------------------
3.797 Looper (main, tid 2) {833b991}
3.797 Message 0: { when=-194ms callback=android.view.View$UnsetPressedState target=android.view.ViewRootImpl$ViewRootHandler }
3.797 Message 1: { when=-156ms what=159 obj=android.app.servertransaction.ClientTransaction@efd342 target=android.app.ActivityThread$H }
3.797 (Total messages: 2, polling=false, quitting=false)


//到这里主线程才空出手来,去处理后面的消息

//这个就是这个onPause消息处理
3.815 I/MainActivity: onPause:
3.815 Looper (main, tid 2) {833b991}
3.815 Message 0: { when=-15ms callback=android.view.Choreographer$FrameDisplayEventReceiver target=android.view.Choreographer$FrameHandler }
3.816 (Total messages: 1, polling=false, quitting=false)
4.808 I/MainActivity: onStop:
  • 我们确实只收到了一个 onPause消息,为什么?那就需要找下大哥AMS问下了

源码debug,向AMS定位问题

  • 当AMS收到startActivity之后,会new一个ActivityRecord,然后后面需要把当前Resumed状态的Activity,onPause掉,所以我们可以直接定位发送Pause消息的地方。
  • com.android.server.am.ActivityStack#startPausingLocked
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
final boolean startPausingLocked(boolean userLeaving, boolean uiSleeping,
ActivityRecord resuming, boolean pauseImmediately) {

//第一次进来mPausingActivity是null,应用没有暂停就没有所谓的mPausingActivity
if (mPausingActivity != null) {
----
}

//第二次进来,如果 mResumedActivity = null 。这里直接return了。就是Trying to pause when nothing is resumed
//mResumedActivity 就是 将要启动的activity com.test/.Main2Activity
ActivityRecord prev = mResumedActivity;
if (prev == null) {
if (resuming == null) {
Slog.wtf(TAG, "Trying to pause when nothing is resumed");
mStackSupervisor.resumeFocusedStackTopActivityLocked();
}
return false;
}

if (prev == resuming) {
Slog.wtf(TAG, "Trying to pause activity that is in process of being resumed");
return false;
}

// prev 就是将要暂停的 之前的 com.test/.MainActivity
mPausingActivity = prev;
mLastPausedActivity = prev;
mLastNoHistoryActivity = (prev.intent.getFlags() & Intent.FLAG_ACTIVITY_NO_HISTORY) != 0
|| (prev.info.flags & ActivityInfo.FLAG_NO_HISTORY) != 0 ? prev : null;

// 设置状态PAUSING android 9在这里面做了 mResumedActivity = null, 和网上以前的博客的不一样
// 后面调用到了onActivityStateChanged
prev.setState(PAUSING, "startPausingLocked");
prev.getTask().touchActiveTime();
clearLaunchTime(prev);

mStackSupervisor.getLaunchTimeTracker().stopFullyDrawnTraceIfNeeded(getWindowingMode());

mService.updateCpuStats();

//调用进程不为null,且调用进程的ApplicationThread不为null
if (prev.app != null && prev.app.thread != null) {
if (DEBUG_PAUSE) Slog.v(TAG_PAUSE, "Enqueueing pending pause: " + prev);
try {
// 这里发送了PauseActivityItem
//通过调用进程的ApplicationThread通知调用进程schedulePauseActivity方法
//那么在 onActivityStateChanged 之内,只会走一次
mService.getLifecycleManager().scheduleTransaction(prev.app.thread, prev.appToken,
PauseActivityItem.obtain(prev.finishing, userLeaving,
prev.configChangeFlags, pauseImmediately));
} catch (Exception e) {
// Ignore exception, if process died other code will cleanup.
Slog.w(TAG, "Exception thrown during pause", e);
mPausingActivity = null;
mLastPausedActivity = null;
mLastNoHistoryActivity = null;
}
} else {
mPausingActivity = null;
mLastPausedActivity = null;
mLastNoHistoryActivity = null;
}
}
  • com.android.server.am.ActivityStack#onActivityStateChanged
1
2
3
4
5
6
7
8
9
void onActivityStateChanged(ActivityRecord record, ActivityState state, String reason) {

//之前的Resumed的ActivityRecord 的 状态改变成新的,就是 state = PAUSING,reason = startPausingLocked
//这里 setResumedActivity = null
if (record == mResumedActivity && state != RESUMED) {
setResumedActivity(null, reason + " - onActivityStateChanged");
}
...
}

豁然开朗

  • onPause 肯定和 ResumedActivity 相关,没有ResumedActivity ,自然就不需要onPause。
    所以在短时间里面,重复进入startPausingLocked就会存在一个状态,也就是 mResumedActivity= null。然后这个startPausingLocked方法提前return了,根本没有发送scheduleTransaction->PauseActivityItem ,所以短时时间里面只发送了一次,也就是下次的mResumedActivity的setState还没调用的之前。
  • 点击事件,所有的startActivity事件都是在 主线程里面执行的
  • 就算在这个for循环里面的这段时间里面收到了AMS发过来的ClientTransaction,也不能立即去执行
  • 第一次启动的activityAMS抛出了onPause的Message,而后面没有抛出
  • 等这个for循环走完之后,再去处理ClientTransaction 消息,去执行当前activity的onPause回调方法,是最后回一个消息给AMS
  • AMS收到消息之后,从TaskRecord的栈顶取出ActivityRecord,执行它的生命周期方法,比如onCreate
  • 这样我们页面展示的就是最后一次的Activity

当你留够了时间?

1
2
3
4
for (int i = 0; i < 4; i++) {
startActivity(new Intent(MainActivity.this, Main2Activity.class));
Thread.sleep(1000);
}
  • 你会发现 之前的 state=INITIALIZING 全部变成了state=STOPPED ,也就是一般的页面跳转情况
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
  * Hist #4: ActivityRecord{1b0bee6 u0 com.test/.Main2Activity t40}
state=RESUMED stopped=false delayedResume=false finishing=false
* Hist #3: ActivityRecord{77e243c u0 com.test/.Main2Activity t40}
state=STOPPED stopped=true delayedResume=false finishing=false
* Hist #2: ActivityRecord{3085c2 u0 com.test/.Main2Activity t40}
state=STOPPED stopped=true delayedResume=false finishing=false
* Hist #1: ActivityRecord{769b0f8 u0 com.test/.Main2Activity t40}
state=STOPPED stopped=true delayedResume=false finishing=false
* Hist #0: ActivityRecord{9808381 u0 com.test/.MainActivity t40}
state=STOPPED stopped=true delayedResume=false finishing=false

Running activities (most recent first):
TaskRecord{557a2f7 #40 A=com.test U=0 StackId=15 sz=5}
Run #4: ActivityRecord{1b0bee6 u0 com.test/.Main2Activity t40}
Run #3: ActivityRecord{77e243c u0 com.test/.Main2Activity t40}
Run #2: ActivityRecord{3085c2 u0 com.test/.Main2Activity t40}
Run #1: ActivityRecord{769b0f8 u0 com.test/.Main2Activity t40}
Run #0: ActivityRecord{9808381 u0 com.test/.MainActivity t40}

mResumedActivity: ActivityRecord{1b0bee6 u0 com.test/.Main2Activity t40}
mLastPausedActivity: ActivityRecord{77e243c u0 com.test/.Main2Activity t40}
  • 而且你会发现主线程的消息队列里面已经收到了很多个生命周期的ClientTransaction回调消息,不再是之前的就只有1个了
1
2
3
4
5
6
7
8
9
10
11
12
.535      Message 0: { when=-3s642ms what=159 obj=android.app.servertransaction.ClientTransaction@4962 target=android.app.ActivityThread$H }
.539 Message 1: { when=-3s606ms what=159 obj=android.app.servertransaction.ClientTransaction@17b4bc5e target=android.app.ActivityThread$H }
.540 Message 2: { when=-3s604ms what=6 target=android.view.ViewRootImpl$ViewRootHandler }
.543 Message 3: { when=-3s123ms what=159 obj=android.app.servertransaction.ClientTransaction@efd342 target=android.app.ActivityThread$H }
.543 Message 4: { when=-2s613ms what=159 obj=android.app.servertransaction.ClientTransaction@4962 target=android.app.ActivityThread$H }
.543 Message 5: { when=-2s606ms what=159 obj=android.app.servertransaction.ClientTransaction@119702d7 target=android.app.ActivityThread$H }
.543 Message 6: { when=-2s85ms what=159 obj=android.app.servertransaction.ClientTransaction@efd342 target=android.app.ActivityThread$H }
.544 Message 7: { when=-1s573ms what=159 obj=android.app.servertransaction.ClientTransaction@4962 target=android.app.ActivityThread$H }
.545 Message 8: { when=-1s567ms what=159 obj=android.app.servertransaction.ClientTransaction@a56cd5ac target=android.app.ActivityThread$H }
.545 Message 9: { when=-1s44ms what=159 obj=android.app.servertransaction.ClientTransaction@efd342 target=android.app.ActivityThread$H }
.546 Message 10: { when=-536ms what=159 obj=android.app.servertransaction.ClientTransaction@4962 target=android.app.ActivityThread$H }
.546 Message 11: { when=-529ms what=159 obj=android.app.servertransaction.ClientTransaction@f1a0fa6d target=android.app.ActivityThread$H }
  • 这样之前activity都是走了onCreate的流程了

总结

  • 我之前以为情况
  • image.png
  • 实际点击返回出现的情况
  • image.png
  • 之前错误的理解将ActivityRecord 与 RunningActivity 一一对应了。
  • ActivityRecord对应的Activity 可能没有及时创建
  • 返回上一个Activity,上一个Activity的状态可能是INITIALIZING OnPause onStop

附录