症状: SPA架构下,在有并发ajax请求的页面加载时,后端过滤器获取微信网页授权信息(网页授权access_token和openid,下统称“网页授权信息”或“授权信息”)出现"errcode:40163, code been used"的问题。
病因:由于前端页面加载时同时有多个并发ajax请求,过滤器中分别对其进行了获取授权信息操作,导致同一个code被多次使用。
治疗方案:将获取到授权信息后放入redis,并在出现code been used问题时,从redis中获取授权信息。
要理解这个问题出现的场景,可能需要大家有一定的微信开发经验,特别是微信网页开发。大家可以通过我之前写的《微信开发之网页开发》进行一定的了解。这里贴一张比较重要的网页授权流程图:
总的来说,为了使前端开发更加透明简单,我采用了后端过滤器的方案,来对用户进行微信网页授权。对于一个需要网页授权信息的url,我们会先进行微信OAuth请求的包装,用户点击包装的url后其实是先去了微信进行授权操作,完成后才跳转至实际的url,并且已经带上了微信返回的code。之后这个页面上所有的请求都会带上此code,后端过滤器发现session中没有授权信息后,会用code去请求微信接口换取网页授权信息(openid和web access_token),并放入session。实际运行中,我们发现在某些页面上,出现了40163的问题。
{"errCode":"40163","errMsg":"code been used, hints: [ req_id: xxx ]"}
这个错误微信返回的很明确了,“code been used”,就是说同一个code已经去换取过网页授权信息了,查看日志,的确看到了同一个code之前已经去请求过微信的接口换取openid。
2018-12-11 11:44:17.588 [http-nio-8080-exec-1] [INFO] [weChatLogger] [WeChatOAuthFilter.java:43] -- 开始获取微信用户openid,url:http://127.0.0.1:8080//api/sign?code=081xivyF1yigd80b9PyF1m8KyF1xivyk&state=vem&ts=1544499857&randomcode=BnPb3RAaNTf3mBmB&signature=be2bf1989687bf45d57125d4acfc8806
2018-12-11 11:44:17.588 [http-nio-8080-exec-1] [INFO] [weChatLogger] [WeChatOAuthFilter.java:61] -- 微信浏览器内请求通过OAuth进行身份验证:081xivyF1yigd80b9PyF1m8KyF1xivyk
URL: //api/sign
2018-12-11 11:44:17.589 [http-nio-8080-exec-1] [INFO] [weChatLogger] [WeChatServiceImpl.java:119] -- 获取网页授权access_token:https://api.weixin.qq.com/sns/oauth2/access_token?appid=wx597d9f0a67692910&secret=e91342abd1457656625d2a027f536b4c&code=081xivyF1yigd80b9PyF1m8KyF1xivyk&grant_type=authorization_code
2018-12-11 11:44:17.683 [http-nio-8080-exec-3] [INFO] [weChatLogger] [WeChatOAuthFilter.java:43] -- 开始获取微信用户openid,url:http://127.0.0.1:8080//api/member?code=081xivyF1yigd80b9PyF1m8KyF1xivyk&state=vem&ts=1544499857&randomcode=Hf6WrSWDnPCTBbSc&signature=bea8729fa50a0034afff9607e8e18d05
2018-12-11 11:44:17.683 [http-nio-8080-exec-3] [INFO] [weChatLogger] [WeChatOAuthFilter.java:61] -- 微信浏览器内请求通过OAuth进行身份验证:081xivyF1yigd80b9PyF1m8KyF1xivyk
URL: //api/member
2018-12-11 11:44:17.683 [http-nio-8080-exec-3] [INFO] [weChatLogger] [WeChatServiceImpl.java:119] -- 获取网页授权access_token:https://api.weixin.qq.com/sns/oauth2/access_token?appid=wx597d9f0a67692910&secret=e91342abd1457656625d2a027f536b4c&code=081xivyF1yigd80b9PyF1m8KyF1xivyk&grant_type=authorization_code
2018-12-11 11:44:17.797 [http-nio-8080-exec-1] [INFO] [weChatLogger] [WeChatServiceImpl.java:123] -- 获取网页授权access_token:{"access_token":"16_pY4toTfS2fC4NiVorqEjEyPFqVRw86X0FT77gute3hOiHJ8wT6FzkgnVkL5xdgAF8wGs4pQhP2rPHamiZI0NhjGlNT1_O-iLUj5ndnDdaEA","expires_in":7200,"refresh_token":"16_YeWmSXcho-G98uZcpYcqlmHkbsthWZPkBQu1S9eR-uetKckvIvS4JBAxJm2PVwbasS08ZzM4iqR5_9-udTFKQvTx5crLHhvqpdJ4ukbD7kQ","openid":"oTZZ0wMsnD-U1ZpbEH_L9fyTSlLs","scope":"snsapi_userinfo","unionid":"ow-sis3Mf5n1pceVq2Po8Ru84dyI"}
2018-12-11 11:44:17.837 [http-nio-8080-exec-3] [WARN] [weChatLogger] [WeChatServiceImpl.java:123] -- 获取网页授权access_token:{"errcode":40163,"errmsg":"code been used, hints: [ req_id: z917ua08573119 ]"}
这里在11:44:17.589
和11:44:17.683
这两个时间点分别由线程1和线程3带着同一个code去微信换取网页授权信息,结果自然是线程1获取到了网页授权而线程3失败并返回“code been used”。
由于前端同时发起的两个ajax请求到/api/sign
和/api/member
,且都带着微信网页授权的code。后端发现session中没有网页授权信息,都进入过滤器处理,所以两个线程都带着code去请求微信接口。到这里为止问题的原因已经找到,其实这个原因并不难分析,关键是在于如何解决。
我心想这还不容易么,加个判断,当返回结果errcode是40163的时候,Thread.sleep个几秒秒,再从session中获取授权信息,那时前一个请求肯定已经把授权信息放到session中了。但结果却是无论是sleep 1秒还是5秒,都无法从session中获取到数据(同学们可以先停一停,自己思考一下这是为什么)。
通过进一步debug,发现两次请求返回的sessionId不同,才意识到问题所在。这里稍微回忆下session的知识点:session是由服务器端为每个客户端(浏览器)创建的会话对象,在使用时才会创建。后端通过把sessionId(tomcat将sessionId成为JSESSIONID,这里统称为sessionId)传回前端,浏览器将其保存在cookie中,在之后的访问中带上此sessionId来获取后端创建的session,在分布式开发时通常使用spring session解决共享session的问题。
说回我们这里的问题。两个新请求打到后端的时候,由于后端还未给该客户端创建session,所以请求里也没带着sessionId。两个线程分别创建了不同的session,自然第二个线程无论等待多久都无法从前一个线程创建的session中获取到授权信息了。
要解决这个问题也很容易,将网页授权信息放入缓存,key为code,在出现code been used时,从缓存中获取信息,并且把网页授权信息同时也放入新的session,这样之后的请求带着新的sessionid还是可以通过session获取到网页授权信息。大家可以先思考一下如何在出现
code been used时从缓存中获取信息。是Thead.sleep?还是轮询?时间定多少合适?
其实这里有一个更优雅的解决方案。用redis list数据结构的阻塞操作BRPOPLPUSH(source, destination, timeout)
。该操作的作用是从source中拿出最左边的元素,并放入destination的最右边,该操作会阻塞直到从source中获取到元素或超时时间timeout到达。这样我们就不用去挖空心思思考sleep多久后去获取合适。这里为什么不使用阻塞操作BRPOP
?因为BRPOP
会把元素拿出并返回,但是这样缓存内的数据就被消费了,如果并发的请求不是两个而是三个或者更多,那么后面的那些请求还是无法从缓存中获取到数据的,所以需要把授权信息放回去,通过把source和destination设置成同一个,就可以实现循环取放的list。对于redis的操作,个人一直使用也比较推荐spring-data-redis里的RedisTemplate类,比jedis更方便。
所以本文的第一张图“SPA下的微信网页授权”中的“将授权信息放入session”这一步就需要实现以下逻辑:
要注意的是,这里的“放入session”实际上是不同的session。
下面贴下redis操作代码供大家参考:
/**
* @Author: Sawyer
* @Description: 网页授权信息的缓存操作
* @Date: Created in 上午10:24 18/12/11
*/
@Service
public class WeChatWebAuthServiceImpl implements WeChatWebAuthService {
@Autowired
RedisTemplate<String, String> redisTemplate;
private final static ObjectMapper om = new ObjectMapper();
/**
* 将授权信息放入缓存
* @param code
* @param weChatBaseAuth
*/
@Override
public void setBaseAuthToRedis(String code, WeChatBaseAuth weChatBaseAuth) {
ListOperations<String, String> lo = redisTemplate.opsForList();
String key = WeChatConst.REDIS_BASE_AUTH + code;
//缓存过期时间10秒
redisTemplate.expire(key, 30, TimeUnit.SECONDS);
try {
lo.leftPush(key, om.writeValueAsString(weChatBaseAuth));
} catch (Exception ex) {
throw new WeChatEx("baseAuth转化为json出错:" + weChatBaseAuth.toString(), ex);
}
}
/**
* 从缓存中获取授权信息,阻塞获取
* @param code
* @return
*/
@Override
public WeChatBaseAuth getBaseAuthFromRedis(String code) {
ListOperations<String, String> lo = redisTemplate.opsForList();
String key = WeChatConst.REDIS_BASE_AUTH + code;
//使用BRPOPLPUSH阻塞获取baseAuth,等待5秒后超时
String baseAuth = lo.rightPopAndLeftPush(key, key, 5, TimeUnit.SECONDS);
try {
return om.readValue(baseAuth, WeChatBaseAuth.class);
} catch (Exception ex) {
throw new WeChatEx("json转化为baseAuth出错" + baseAuth, ex);
}
}
}
这个问题其实还有个解决方案:前端在页面的加载时先调一个统一个/createSession接口,其他的ajax请求都在这个接口返回后再调用。这样就不会出现多session的问题,不过应该要注意在无需session的页面不要调用,因为创建session也是有开销的。
记录这个问题的原因并不是说这个问题有多难排查,而是想分享一下redis阻塞队列操作在多线程下的一个很好的使用场景。希望能够对大家有帮助。