通过WxJava获取微信AccessToken出现acquire timeouted问题

WxJava是一个目前应用广泛的微信SDK工具开发包，本文记录一个WxJava获取微信AccessToken失败出现acquire timeouted的问题。

1. 故障现象

最近产线出现了一个严重的技术故障问题，用户无法登录长达1个多小时，通过查看日志发现和WxJava相关，在故障期间内，WxJava一直无法正常获取微信Access Token，报acquire timeouted的错误，见下图。

期间尝试重启两次，在19:20第一次重启应用后问题有所减弱，但是过了5分钟又重新大量发生，直到第二次重启应用后问题消失。

2. 问题定位

通过查看错误日志的堆栈信息，

java.lang.RuntimeException: acquire timeouted
    at cn.binarywang.wx.miniapp.config.impl.WxMaRedisConfigImpl$DistributedLock.lock(WxMaRedisConfigImpl.java:332)
    at cn.binarywang.wx.miniapp.api.impl.WxMaServiceImpl.getAccessToken(WxMaServiceImpl.java:110)
    at cn.binarywang.wx.miniapp.api.impl.WxMaServiceImpl.executeInternal(WxMaServiceImpl.java:249)
    at cn.binarywang.wx.miniapp.api.impl.WxMaServiceImpl.execute(WxMaServiceImpl.java:215)
    at cn.binarywang.wx.miniapp.api.impl.WxMaServiceImpl.get(WxMaServiceImpl.java:199)
    at cn.binarywang.wx.miniapp.api.impl.WxMaServiceImpl.jsCode2SessionInfo(WxMaServiceImpl.java:178)
    at cn.binarywang.wx.miniapp.api.impl.WxMaUserServiceImpl.getSessionInfo(WxMaUserServiceImpl.java:28)

可以看到和WxJava通过分布式锁获取token有关，产线用的WxJava代码版本是3.6.0，之前已经稳定运行了一年多。

下载相应版本WxJava代码，找到报错的代码行，

// 类文件 - cn.binarywang.wx.miniapp.api.impl.WxMaServiceImpl

public class WxMaServiceImpl implements WxMaService {

  public String getAccessToken(boolean forceRefresh) throws WxErrorException {
    if (!this.getWxMaConfig().isAccessTokenExpired() && !forceRefresh) {
      return this.getWxMaConfig().getAccessToken();
    }

    Lock lock = this.getWxMaConfig().getAccessTokenLock();
    lock.lock(); // <-- 问题发生代码行 WxMaServiceImpl.java:110
    try {
      String url = String.format(WxMaService.GET_ACCESS_TOKEN_URL, this.getWxMaConfig().getAppid(),
        this.getWxMaConfig().getSecret());
      try {
        HttpGet httpGet = new HttpGet(url);
        if (this.getRequestHttpProxy() != null) {
          RequestConfig config = RequestConfig.custom().setProxy(this.getRequestHttpProxy()).build();
          httpGet.setConfig(config);
        }
        try (CloseableHttpResponse response = getRequestHttpClient().execute(httpGet)) {
          String resultContent = new BasicResponseHandler().handleResponse(response);
          WxError error = WxError.fromJson(resultContent, WxType.MiniApp);
          if (error.getErrorCode() != 0) {
            throw new WxErrorException(error);
          }
          WxAccessToken accessToken = WxAccessToken.fromJson(resultContent);
          this.getWxMaConfig().updateAccessToken(accessToken.getAccessToken(), accessToken.getExpiresIn());

          return this.getWxMaConfig().getAccessToken();
        } finally {
          httpGet.releaseConnection();
        }
      } catch (IOException e) {
        throw new RuntimeException(e);
      }
    } finally {
      lock.unlock();
    }

  }
}

// 类文件 - cn.binarywang.wx.miniapp.config.impl.WxMaRedisConfigImpl$DistributedLock

public class WxMaRedisConfigImpl implements WxMaConfig {

  private class DistributedLock implements Lock {

    private JedisLock lock;

    private DistributedLock(String key) {
      this.lock = new JedisLock(getRedisKey(key));
    }

    @Override
    public void lock() {
      try (Jedis jedis = jedisPool.getResource()) {
        if (!lock.acquire(jedis)) {
          throw new RuntimeException("acquire timeouted"); // <-- 问题发生代码行 WxMaRedisConfigImpl.java:332
        }
      } catch (InterruptedException e) {
        throw new RuntimeException("lock failed", e);
      }
    }

    // ...
  }
}

上面的代码主要是通过redis分布式锁，使得只有一个进程中的一个线程执行token获取并存储到redis，梳理getAccessToken()方法的执行路径，可以发现其大概经历的步骤如下，

若仔细研读这个流程图，可以发现其中有很多相互抢占竞争资源的问题，其中有竞争的资源有3处，

1. DistributedLock.lock()：分布式锁，多个进程/线程抢占这个锁，只有获取到此锁的线程才能执行锁更新操作。
2. jedisPool.getResource()：单进程中多个线程竞争从连接池获取redis连接。
3. JedisLock.acquire()和JedisLock.release()：两个方法被synchronized修饰，这个是一个比较隐蔽的同步琐，被单进程中的多个线程所竞争抢占。

2.1 问题一：在jedisPool.getResource()时等待超时

如下图所示，

整个获取token过程需要多次获取jedisPool.getResource()，特别是获取到分布式锁的线程，即使通过http请求获取到了微信token之后，并不一定能够顺利地将token写入redis，因为写入时还需要再获取一次redis连接，若获取redis连接失败，则可能刷新token失败。

2.2 问题二：多次频繁刷新token

如下图所示，

在多个并发情况下，受到分布式锁的影响，当拥有锁的一个线程在更新token的时候，多个线程会被阻塞在distributedLock.lock()，但第一个拥有分布式锁的线程更新完token，所有其它阻塞的线程会继续执行后续的token刷新操作，进而导致频繁刷新token，在最差情况下，可能会导致一直无序地循环刷新token。

2.3 问题三：无法通过JedisLock.release()释放分布式锁

如下图所示，

当拥有分布式锁的一个线程结束更新token时，需要通过JedisLock.release()释放分布式锁，但是注意JedisLock.acquire()和JedisLock.release()两个方法被synchronized修饰，它们两个需要竞争抢占同一个JedisLock对象上的同步锁，很有可能的情况下，由于其它线程不停的acquire()，导致当前拥有分布式锁的线程永久无法得到释放。

3. 解决方案

可以看到3.6.0版本上的WxMaServiceImpl.getAccessToken()很多问题，根本原因就是在代码实现中几个竞争资源被来回穿插抢占，如何将锁资源的竞争关系解放，是解决关键。

如下是一个解决方案的示例代码，

// 类文件 - cn.binarywang.wx.miniapp.api.impl.WxMaServiceImpl

  private String getAccessToken(boolean forceRefresh) throws WxErrorException{
    if (!this.getWxMaConfig().isAccessTokenExpired() && !forceRefresh) {
      return this.getWxMaConfig().getAccessToken();
    }

    // 若是redis分布式锁实现，则走新方法更新token
    if (this.getWxMaConfig() instanceof WxMaRedisConfigImpl){
      return getAccessTokenV2((WxMaRedisConfigImpl) this.getWxMaConfig(), forceRefresh);
    }

    // 略...
  }

  /**
   * 更新redis中的token并返回
   * @param redisConfig
   * @param forceRefresh
   * @return
   */
  private String getAccessTokenV2(WxMaRedisConfigImpl redisConfig, boolean forceRefresh) throws WxErrorException{

    // 处理1：获取分布式锁的当前线程，后续都将使用当前jedis连接完成后续操作
    Jedis jedis = redisConfig.getJedis();

    try{
      DistributedLock lock = redisConfig.AccessTokenLock();

      lock.lock(jedis);
      log.info("当前线程获取到redis分布式锁");
      try {

        // 处理2：二次判断token是否有效
        if (!redisConfig.isAccessTokenExpired(jedis) && !forceRefresh) {
          log.info("二次判断token有效，无需再次刷新");
          return redisConfig.getAccessToken(jedis);
        }

        String url = String.format(WxMaService.GET_ACCESS_TOKEN_URL, this.getWxMaConfig().getAppid(),
          this.getWxMaConfig().getSecret());
        try {
          HttpGet httpGet = new HttpGet(url);
          if (this.getRequestHttpProxy() != null) {
            RequestConfig config = RequestConfig.custom().setProxy(this.getRequestHttpProxy()).build();
            httpGet.setConfig(config);
          }
          Date start = new Date();

          try (CloseableHttpResponse response = getRequestHttpClient().execute(httpGet)) {
            Date end = new Date();
            String resultContent = new BasicResponseHandler().handleResponse(response);
            WxError error = WxError.fromJson(resultContent, WxType.MiniApp);
            if (error.getErrorCode() != 0) {
              throw new WxErrorException(error);
            }
            WxAccessToken accessToken = WxAccessToken.fromJson(resultContent);
            redisConfig.updateAccessToken(jedis, accessToken.getAccessToken(), accessToken.getExpiresIn());
            return accessToken.getAccessToken();
          } finally {
            httpGet.releaseConnection();
          }
        } catch (IOException e) {
          throw new RuntimeException(e);
        }
      } finally {
        lock.unlock(jedis);
      }
    } finally {
      jedis.close();
    }
  }

// 类文件 - cn.binarywang.wx.miniapp.config.impl.WxMaRedisConfigImpl$DistributedLock

  /**
   * 基于redis的分布式锁.
   * 处理3：通过已有jedis连接获取和释放分布式锁，见lock()/unlock()
   */
  private class DistributedLock implements GuoquanRedisLock {

    private JedisLock lock;

    private DistributedLock(String key) {
      this.lock = new JedisLock(getRedisKey(key));
    }

    @Override
    public void lock(Jedis jedis) {
      try {
        if (!lock.acquire(jedis)) {
          throw new RuntimeException("acquire timeouted");
        }
      }catch (InterruptedException e){
        throw new RuntimeException("lock failed", e);
      }
    }

    @Override
    public void unlock(Jedis jedis) {
      lock.release(jedis);
    }

  }

在上面的代码中，主要改变如下，

1. 处理1：获取分布式锁的当前线程，后续都将使用当前jedis连接完成后续操作。
2. 处理2：二次判断token是否有效，避免循环刷新token。
3. 处理3：通过已有jedis连接获取和释放分布式锁，见lock()/unlock()。

应用通过如上代码上线后，acquire timeouted的问题没有再出现，问题得到解决。

4. 发生的版本和后续WxJava优化

上面的问题存在WxJava的多个版本，包括v3.6.0到v3.8.0的版本。

直到v3.9.0及后续版本，可以看到相关问题的陆续修复，如下是两个相关的代码提交，

• 版本v3.9.0：优化小程序获取token逻辑，减少刷新请求次数，修复同上述处理2，

      if (!this.getWxMaConfig().isAccessTokenExpired() && !forceRefresh) {
        return this.getWxMaConfig().getAccessToken();
      }

• 版本v4.2.0：标记JedisDistributedLock组件标记为Deprecated，不推荐使用来获取分布式锁。

在locks同一目录下有另外一个RedisTemplateSimpleDistributedLock的实现供配置使用，其在版本v3.9.0已经支持，需要进行如下配置，

# 存储配置redis(可选)
wx.mp.config-storage.type = redistemplate             # 配置类型: Memory(默认), Jedis, RedisTemplate

更多配置请参考README文件。

5. 思考

有些问题一直不出现，不代表着不存在，在高并发情况下锁、线程池、连接池等资源竞争问题都将无限放大，可靠的软件产品需要经历一个持续不断打磨的历练过程。