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