记一次微信公众号accesstoken失效的排查

losetowin 发布于:2016-1-20 23:11 分类:技术  有 8126 人浏览,获得评论 0 条 标签: redis ttl 

本文地址:http://www.dutycode.com/redis_ttl_0_paicha.html
除非注明,文章均为 www.dutycode.com 原创,欢迎转载!转载请注明本文地址,谢谢。
起因:
     说起起因,其实蛮不好意思的,因为反映了我们的监控做的不够完善。
     我们在做微信公众号开发的时候,将accesstoken值缓存到了redis中,有效时间设置成了30分钟,但是,有一天我们发现,公众号回复消息的时候,不能正常给用户回复内容了。我们查看日志,发现是因为accesstoken不对,导致推送消息时认证不通过。

分析:
     我们考虑到了以下几点可能造成的原因:
          1、accesstoken被人调用刷新了,但是未写入到redis中,导致线上程序取得accesstoken已经失效。
          2、因为redis刚迁移机房,所以潜意识认为新机房redis存在问题。并且,之前未存在问题,迁移机房之后产生的问题。

解决:
     针对上面两点原因,我们进行分析:
          第一点,我们之前已经整合过相关的代码,将accesstoken的获取和设置封装了一个对外提供的服务,现有的工程里面也把相关的获取accesstoken的代码切换成了封装好的服务。
          所以,现有工程里面应该不会私自调用微信api刷新accesstoken,so,我们从最近(redis迁移机房前后5天内)新上的站点/服务开始看。找了相关的负责人,查看代码之后,发现,并没有代码再直接调用微信api,而是全部都通过封装好的服务获取accesstoken。
          问题就变得好玩了,既然都在调用封装后的方法,为什么还会出现accesstoken失效的情况呢?     
          突然想到一点,虽然现有工程没有直接调用微信api,会不会有我们不知道的程序再调用呢?如果是这样,那么微信公众帐号里面的接口调用数应该会很多,所以我们去看了下微信开发者平台的接口调用统计,结果,发现接口的调用次数为1
          这就更好玩了,即使是正常情况下,我们的accesstoken值的有效时间是30分钟,那么我们的程序一天至少有48次需要调用微信api。当时的时间是中午12点左右,理论上会有24次左右的调用才对,微信的统计一般不会出错。这样看起来,思路貌似有点明朗了。
          接下来可能的原因,有可能是,我们代码里面有地方对accesstoken的值设置的有效时间不是30分钟,或者是长期有效了,导致程序发现redis里面存在,所以就没有去请求微信api。
          我们连上redis看了一下key值的剩余时间。如下图:
          ttl_0_1.png
          发现ttl的结果是0.这就有点不太正常了。正常情况下,返回的结果应该是-1, -2, 或者是 大于0 的情况,如果一个key值失效了,那么应该是-2才对(具体可以参见:http://redis.io/commands/ttl
          那这个0是怎么回事呢?
          我们手动设置了一个key值,并把它的有效期设置成了10s,发现,这个key值10s后,没有在redis中消失,而是依旧存在,并且,ttl的结果是0.
          所以问题,基本确定原因了,是因为,redis中accesstoken这个key值到了有效期之后,并没有失效,而是依旧存储在redis中,并且ttl结果为0.所以,程序取到的accesstoken值是很久之前的有效值(微信的accesstoken是2小时失效),所以肯定校验不通过。
          知道了这个原因,那么问题就在redis上了,本着解决问题的精神,我们利用了我们的伟大的工具googole和百度(会被吐槽吗?),发现这个问题,竟然也有人遇到过。然后,很简单的我们再相关文章中知道了原因:
     如果一个redis作为slave,且将slave-read-only设置为off,并写入了一个带有TTL的key时,当key过期后,该key是不会被Redis删除的,且TTL在过期后永远为0
     我们看了一下我们的redis角色,果然是slave (info一下,你就知道)
          ttl_0_2.png
     所以,我们赶紧联系了一下我们的相关同学,帮忙将角色改成了master角色,改完之后,程序正常。
     BTW:为什么会出现我们连接的是从库,并且产生了写的情况呢?正常情况下,我们肯定是读写再主库上,或者是主库写,从库读。这次的问题,在于,迁移redis到新机房的时候,要做数据同步,所以临时将新机房的redis设置成了从库角色,但是程序切换完之后,并没有及时把角色切换成主库。(现在用的是 redis的sentinel,具体可以参见:http://redis.io/topics/sentinel)切换角色只需要将原来的主库下掉,这边的从库就自动成为主库了。

总结:
     这基本上算是一次线上事故,并且,我们没有及时发现问题,导致了线上微信回复功能失效了一段时间(影响时间1.5天),发现问题并处理问题响应过慢。反映了我们的监控机制不够完善,我们为此也添加了一些监控,比如监控redis中accesstoken值一天是否更新了足够的次数或者是否更新了过多的次数,如果发现有问题,便会及时短信报警。


备注:
     由于出现线上bug的时候的redis截图没有存储,所以上述截图是根据当时的场景做的还原,不涉及到公司机密。
          
          
      

版权所有:《攀爬蜗牛》 => 《记一次微信公众号accesstoken失效的排查
本文地址:https://www.dutycode.com/redis_ttl_0_paicha.html
除非注明,文章均为 《攀爬蜗牛》 原创,欢迎转载!转载请注明本文地址,谢谢。