手机休眠引发的“血案” - clarkehe/Android GitHub Wiki

对于Android休眠机制的关注，还得从最近遇到一个问题说起。

问题是这样的：App持有WX的票据（WX登陆成功后返回的KEY），但这个票据是有有效期的（现在是2个小时）。和服务器交互需要用到这个票据，总不能在票据过期后让用户再重新登陆吧。因此要在票据失效前静默的更新下这个票据，App的实现逻辑是这样的：

//每次拿到最新票据后，根据票据有效期，通过Handler发送一个延迟消息，比如票据是2个小时，我们发送一个在1时45分后的延迟消息
mTokenRefreshHandler.removeMessages(REFRESH_TOKEN);
mTokenRefreshHandler.sendEmptyMessageDelayed(REFRESH_TOKEN, delaySecMillis < 0 ? DEFAULT_REFRESH_INTERVAL : delaySecMillis);

这个代码很简单，从逻辑上看也没有什么问题。可有同事反馈，他遇到了一个提示，是说票据失效，请重新登陆。看了下代码，弹出这个提示有3个地方，都是使用WX票据，通过协议将票据传给服务器，服务器通过专门一个结果码来反馈票据过期。很显示就是服务器回包，结果码是票据过期。

按代码逻辑，票据应该是有自动更新的，不会过期。取了日志分析发现，从发送延时消息开始，已经超过了两个小时，但没有延迟消息处理的日志，整个日志文件是一处也没发现。由于延迟时长太长，不好自测，将延迟改为10秒钟后自测，观察日志，消息有处理，正常。

怪了？开始怀疑进程是不是放到后台被回收了，因为app没有一直使用，有一段时间是放到后台的，看日志确认没有收回。如果app被回收了，再次使用时是重新更新票据，延迟的逻辑也是重新生效。

又怀疑android的消息机制会不会丢消息，看了文档应该不可能，只要进程不退，消息循环没退出，消息不会丢失；会不会是延迟消息没有发送成功，加了日志看sendEmptyMessageDelayed的返回值，正常。

用另一台手机自测，启动app后，将手机放在那时挂两个小时。两个小时后取日志发现，app没有回收，还没有延迟消息处理的逻辑。很显然这是一个必现的问题。

仔细分析后发现，在等待延迟消息更新票据的这段时间内，app都是在后台运行。想起之前遇到的一个问题，vivo手机在开始省电模式后，将所有后台app的进程挂起，即使手机还没有熄屏或用户正在操作其他的app。测试的手机是Nexus 5，没有这样一个省电就挂起进程的逻辑。但问题应该还是跟app在后台运行有关。

app处理后台逻辑最常见的是使用service，开始想是不是应该是这个延迟更新逻辑放到一个service就正常了。但也不是太确定，但可以确定的是应该什么“坑”我们还是知道。于是google了下android background app相关资料，果然在一篇文章中提到了休眠与alarm的技术。

为了简化问题，写了一个测试程序，每隔一分钟发一个延迟消息。打日志发现，延迟消息在手机熄屏休眠后，延迟的时间变长了。如果手机保持充电且不熄屏，延迟消息很准时的就处理了。看来延迟消息确实受手机休眠的影响。为什么会这样尼，分析了下消息机制相关代码，找到了下面的关键代码。

    /**
     * Returns milliseconds since boot, not counting time spent in deep sleep.
     *
     * @return milliseconds of non-sleep uptime since boot.
     */
    native public static long uptimeMillis();

    public final boolean sendMessageDelayed(Message msg, long delayMillis)
    {
        if (delayMillis < 0) {
            delayMillis = 0;
        }
        return sendMessageAtTime(msg, SystemClock.uptimeMillis() + delayMillis);
    }

   Message next()
   {
     ...
     // Try to retrieve the next message.  Return if found.
     final long now = SystemClock.uptimeMillis();
     Message prevMsg = null;
     Message msg = mMessages;
     if (msg != null) {
      if (now < msg.when) {
          // Next message is not ready.  Set a timeout to wake up when it is ready.
          nextPollTimeoutMillis = (int) Math.min(msg.when - now, Integer.MAX_VALUE);
       } 
     }
    ...
   ｝

next是MessageQueue.java中的函数，主要功能是从队列中取出可以处理的消息。对于延迟消息，有一个处理的时间点(when属性)。在取消息是，会判断消息的是否到期，就是使用当前时间now和消息when属性进行比较，这都没什么问题。问题在于计算时间的函数：SystemClock.uptimeMillis()，这个函数获取的是自系统启动以来的时间，但不包括系统休眠的时间。

举个例子，在发送延迟消息时，uptimeMillis的值是0，消息延迟2小时，msg.when = 2小时。如果在0.5小时后，手机进入了休眠且持续了1.5小时，接着退出休眠，此时2个小时已经过去了，延迟消息应该处理了。但按上面逻辑，虽然过了2个小时，now的值是0.5，now < msg.when，消息延迟的时间还没到，不会处理。

延迟2个小时后处理的消息，虽然实际时间已经过了2个小时，可由于手机休眠了1.5个小时，消息机制认为才过了0.5个小时，消息就没有处理。归纳一句话**：延迟消息会因为手机休眠而进一步延迟**。

回到实际的问题，手机挂了近两个小时，看日志发现没有票据更新的逻辑，是因为对于消息机制而言，2个小时确实还没有到。2个小时的延迟，会因为手机的休眠，实际延迟会大于2个小时。票据超过2个小时没更新，再使用当然会提示过期。

为了避免休眠对票据更新的影响，应该使用alarm，alarm不受休眠的影响。