记录一次解决onDestroy 延迟10s调用问题

一、问题表现

FirstActivity有个点击事件可以进入到SecondActivity，但是点击的时候有个Tag防止起多个SecondActivity，而这个Tag是在SecondActivity#onDestroy()里重置的，在某种情况下，Tag不生效了，于是便在SecondActivity#onDestroy()增加日志，发现onPause()未调用，onDestroy()延迟了10s调用。

二、问题原因

前人栽树后人乘凉，感谢ZCJ风飞大佬的分析:

深入分析Android中Activity的onStop和onDestroy()回调延时及延时10s的问题

通过这位大佬分析可以得知：在下一个要显示的Activity的回调onResume之后，ActivityThread会注册一个主线程消息队列的一个IdleHandler，用于ActivityManagerService处理Activity#onStop()和Activity#onDestroy()，若主线程一直在循环处理消息队列中累积的Message，则上述的IdleHandler一直得不得调用，作为一个健壮的ROM，AMS会发送一个延时10s的消息，确保正常流程行不通的情况下也能销毁Activity，从而表现上便是onPause()未调用，onDestroy()延迟了10s调用。

三、问题验证

再次感谢ZCJ风飞大佬：

public class SecondActivity extends Activity {
private static final String TAG = "SecondActivity";
private Handler handler = new Handler();
@Override
protected void onCreate(@Nullable Bundle savedInstanceState) {
super.onCreate(savedInstanceState);
setContentView(R.layout.activity_main);
postMsg();
}
private void postMsg() {
handler.post(new Runnable() {
@Override
public void run() {
try {
// 在主线程中休眠一小段时间
// 用来模拟主线程中诸如复杂的绘制、复杂数据处理、帧动画等等操作
Thread.sleep(20);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
});
handler.postDelayed(new Runnable() {
@Override
public void run() {
postMsg();
}
}, 10);
}
@Override
protected void onDestroy() {
super.onDestroy();
Log.i(TAG, "onDestroy: ");
}
@Override
protected void onStop() {
super.onStop();
Log.i(TAG, "onStop: ");
}
}

通过上述示例代码，的确出现了onDestroy()延迟了10s调用，故问题原因肯定是主线程MessageQueue在循环处理累积的Message。那么问题来了，这些累积的Message是什么？又是谁发送的？

四、问题解决

1.累积的Message是什么

由Handler机制可以，主线程持有Looper, 而Looper内部维持了一个MessageQueue用于调度各种Message，故可以尝试通过MessageQueue去了解Message是什么；阅读Looper的源码，发现有以下代码:

    /**
* Dumps the state of the looper for debugging purposes.
*
* @param pw A printer to receive the contents of the dump.
* @param prefix A prefix to prepend to each line which is printed.
*/
public void dump(@NonNull Printer pw, @NonNull String prefix) {
pw.println(prefix + toString());
mQueue.dump(pw, prefix + "  ", null);
}

MessageQueue#dump()源码如下：

    void dump(Printer pw, String prefix, Handler h) {
synchronized (this) {
long now = SystemClock.uptimeMillis();
int n = 0;
for (Message msg = mMessages; msg != null; msg = msg.next) {
if (h == null || h == msg.target) {
pw.println(prefix + "Message " + n + ": " + msg.toString(now));
}
n++;
}
pw.println(prefix + "(Total messages: " + n + ", polling=" + isPollingLocked()
+ ", quitting=" + mQuitting + ")");
}
}

看起来可以拉取到主线程消息队列中某一刻的Message列表，尝试以下代码:

private void tryDump() {
// 仅仅用于示例，不建议直接new Thread()
new Thread() {
@Override
public void run() {
while (true) {
Looper.getMainLooper().dump(new Printer() {
@Override
public void println(String x) {
Log.i("SecondActivity", "println: " + x);
}
}, "");
try {
Thread.sleep(500);
} catch (Exception ignore) { }
}
}
}.start();
}

得到类似如下日志:

其中when是指当前时候之后多少ms之后该执行此Message,看起来似乎这个SlideShineImageView有问题，便兴奋的将其修改成普通的ImageView，沮丧的是仍旧有问题，修改后的日志如下：

于是便陷入了沉思，细想可以发现此方法存在致命漏洞：无法打印主线程中所有的Message！！！再次阅读Looper的源码，发现有如下代码:

    public static void loop() {
// *** 省略部分代码 ***
for (; ; ) {
Message msg = queue.next(); // might block
if (msg == null) {
// No message indicates that the message queue is quitting.
return;
}
// This must be in a local variable, incase a UI event sets the logger
final Printer logging = me.mLogging;
if (logging != null) {
logging.println(">>>>> Dispatching to " + msg.target + " " +
msg.callback + ": " + msg.what);
}
// *** 省略部分代码 ***
if (logging != null) {
logging.println("<<<<< Finished to " + msg.target + " " + msg.callback);
}
// *** 省略部分代码 ***
}
}

故若设置了Printer则可打印出主线程执行的Message，Looper中提供了此方法：

/**
* @param printer A Printer object that will receive log messages, or
* null to disable message logging.
*/
public void setMessageLogging(@Nullable Printer printer) {
mLogging = printer;
}

尝试设置，得到类似如下日志：

通过了解View的绘制了解便知，主线程累积的Message是系统的绘制消息。一般来说，只有调用了View#requestLayout()或者View#invalidate()才会引起重绘

2.罪魁祸首是谁

虽然知道了问题的原因，但是由于View纵多，直接在所有View中增加日志工作量大且容易做无用功，联想到View本身是一棵树，View#requestLayout()或者View#invalidate()最终肯定会回调到树根上(DecorView)，故可以尝试通过重写FirstActivity的ContentView中的某些方法从而找到问题View。

查看View#requestLayout()源码:

    public void requestLayout() {
// *** 省略部分代码 ***
if (mParent != null && !mParent.isLayoutRequested()) {
mParent.requestLayout();
}
if (mAttachInfo != null && mAttachInfo.mViewRequestingLayout == this) {
mAttachInfo.mViewRequestingLayout = null;
}
}

最终回调到ViewRootImpl#requestLayout(),代码如下:

    public void requestLayout() {
if (!mHandlingLayoutInLayoutRequest) {
checkThread();
mLayoutRequested = true;
scheduleTraversals();
}
}

看代码意思便是接下来会触发View的绘制流程相关逻辑，故尝试使用如下ViewGroup作为FirstActivity的根布局:

public class FirstActivityRootLayout extends FrameLayout {
private static final String TAG = "FirstActivityRootLayout";
public FirstActivityRootLayout(Context context, AttributeSet attributeSet) {
super(context, attributeSet);
}
@Override
public void requestLayout() {
Log.i(TAG, "requestLayout: ", new Exception());
super.requestLayout();
}
}

但是requestLayout()的代码逻辑执行正常，于是便查看View#invalidate()的相关流程，invalidate()代码如下：

 public void invalidate() {
invalidate(true);
}

public void invalidate(boolean invalidateCache) {
invalidateInternal(0, 0, mRight - mLeft, mBottom - mTop, invalidateCache, true);
}

void invalidateInternal(int l, int t, int r, int b, boolean invalidateCache,
boolean fullInvalidate) {
// *** 省略部分代码
if ((mPrivateFlags & (PFLAG_DRAWN | PFLAG_HAS_BOUNDS)) == (PFLAG_DRAWN | PFLAG_HAS_BOUNDS)
|| (invalidateCache && (mPrivateFlags & PFLAG_DRAWING_CACHE_VALID) == PFLAG_DRAWING_CACHE_VALID)
|| (mPrivateFlags & PFLAG_INVALIDATED) != PFLAG_INVALIDATED
|| (fullInvalidate && isOpaque() != mLastIsOpaque)) {
// *** 省略部分代码
final ViewParent p = mParent;
if (p != null && ai != null && l < r && t < b) {
final Rect damage = ai.mTmpInvalRect;
damage.set(l, t, r, b);
// 关键代码
p.invalidateChild(this, damage);
}
// *** 省略部分代码
}
}

从上述代码可知，invalide()只会刷新当前View所在的区域，故直接在FirstActivityRootLayout重写invalide()方法是不能找到问题View的，因为其可能不是全屏的；注意到上述代码中的invalidateChild()方法，其在ViewGroup中代码如下:

    /**
* Don't call or override this method. It is used for the implementation of
* the view hierarchy.
*
* @deprecated Use {@link #onDescendantInvalidated(View, View)} instead to observe updates to
* draw state in descendants.
*/
@Deprecated
@Override
public final void invalidateChild(View child, final Rect dirty) {
final AttachInfo attachInfo = mAttachInfo;
if (attachInfo != null && attachInfo.mHardwareAccelerated) {
// HW accelerated fast path
onDescendantInvalidated(child, child);
return;
}
ViewParent parent = this;
if (attachInfo != null) {
// *** 省略部分代码
do {
View view = null;
if (parent instanceof View) {
view = (View) parent;
}
// *** 省略部分代码
parent = parent.invalidateChildInParent(location, dirty);
// *** 省略部分代码
} while (parent != null);
}
}

此方式是final方法，故无法被子类重写;支持硬件加速的设备会走onDescendantInvalidated()，否则走invalidateChildInParent()，其最终都会调用到ViewRootImpl#scheduleTraversals()，触发View的绘制流程相关逻辑，注意到这两个方法均非final，于是修改FirstActivityRootLayout代码:

public class FirstActivityRootLayout extends FrameLayout {
private static final String TAG = "FirstActivityRootLayout";
public FirstActivityRootLayout(Context context, AttributeSet attributeSet) {
super(context, attributeSet);
}
@Override
public void requestLayout() {
Log.i(TAG, "requestLayout: ", new Exception());
super.requestLayout();
}
@Override
public ViewParent invalidateChildInParent(int[] location, Rect dirty) {
Log.i(TAG, "invalidateChildInParent: ", new Exception());
return super.invalidateChildInParent(location, dirty);
}
@Override
public void onDescendantInvalidated(@NonNull View child, @NonNull View target) {
super.onDescendantInvalidated(child, target);
Log.i(TAG, "onDescendantInvalidated: ", new Exception());
}
}

终于，满屏重复日志:

故问题原因便是：在自定义TextView#onDraw()中调用了setTextColor()，间接调用了invalidate()，造成循环调用，从而造成主线程中全是请求绘制的消息，于是便出现onPause()未调用，onDestroy()延迟了10s调用现象。

  • 站在巨人的肩膀上，再次感谢ZCJ风飞大佬：
    深入分析Android中Activity的onStop和onDestroy()回调延时及延时10s的问题

以上是 记录一次解决onDestroy 延迟10s调用问题 的全部内容， 来源链接： utcz.com/a/29655.html

回到顶部