性能文章>刚线上又出现一个问题。。。热乎的>

刚线上又出现一个问题。。。热乎的原创

451637

大家好,我是yes。我又来送线上排查经历啦!

事情是这样的,今天同事给我反馈了一个问题。

3F924D8A-5048-4E0B-B6F9-652954610010.png

因为我们的应用需要从第三方那边同步订单的信息,如果用户有一段时间未进入订单页面,则再次进入之后会自动进行一次全量的从第三方拉取订单的操作,这样能可及时更新订单信息,防止用户操作过期的订单。


近期,这个同事发现每次点订单列表都会触发全量拉取,这明显就不合理,非常耗费后端任务的资源。


一开始我觉得这跟我肯定没关系,可能是前端代码出了 BUG (哈哈哈,上次也是这样想)。


所以我告知了前端的同事,经过排查,他很确定的告诉我代码肯定没问题,只有超过一小时没同步过订单的用户,再次进入订单页面进去才会触发拉取。


我看他信誓旦旦的样子,信了。没办法,只能我自己去研究研究了。这一研究还真被我发现了问题,并追根溯源发生竟是以前碰到的一个问题引起的,真是一环扣这一环!

开始排查

我先登录测试账号,发现无法复现同事所说的每次点击订单列表都会触发全量拉取订单的情况。好嘛,出师不利。随即跟他进行了一番沟通,我发现,还竟然是个例?于是,找出个别会出现这样情况的用户。

 

模拟一看,全量订单拉取任务执行的时候,其实报错了,报的错是 accessToken 过期。我们和第三方授权走的是 oauth2,也就是说,第三方授权给我们的 token 过期了,导致我们订单拉取接口报错了,于是任务执行失败。


于是乎,我又怀疑上刷新 token 的代码了,因为我们有个任务,会根据 token 的过期时间,提前利用 refreshToken 去换取最新的 token 。


所以,讲道理不可能会出现 token 过期的报错,所以我目测这肯定是刷新 token 的任务有问题,导致 token 过期,使得订单拉取任务执行失败。然后前端不会记录失败的任务时间,因此再次进入订单页面发现超过一小时未同步过,随即触发全量拉取。


这时,我想找寻负责刷新 token 的任务的同事,找了一圈之后,发现原来是我写的....我检查了一下定时刷新任务确实是在跑的,那只能是刷新 token 的请求出了问题,我一查日志,果然有错!

DB4E125C-8B00-496C-BEE0-269326A5B95A.png


这个错,我在之前就看见过。这是调用第三方刷新 token 接口,然后由第三方返回的错误,我当时看着没任何头绪,缺少 code ,啥 code?

CF1562A2-2448-4905-8147-7FC4EA9E8249.png

从上面的代码可以看到,刷新 token 的接口只需要传这两个参数,没啥别的运算之类的。

并且,当时看到这个错误的时候,我立马在本地拿 refreshToken 进行测试调用,发现根本不报错,能成功返回 accessToken。

并且经过我多天的观察,我发现有些用户的刷新是可以成功的,而有些是不行的。

因为,刷新 token 的接口如此简单,且报错是对方返回的,且从报错信息来看跟我好像没啥关系,理所当然,我认为肯定是对方接口有问题,我怎么看我这边根本就没有犯错的余地(记住这句话)。

所以,之前遇到这个问题我就说处理不了,直接甩锅给第三方(因为第三方出过很多次问题)了,谁知道现在又绕回来了。

没办法,又遇上了这个问题,现在我只能拿这个用户的 refreshToken 在本地再试试看了。

而恰巧,之前我都从数据库从库中查找 refreshToken ,这次我用公司内部的工具来获取,然后就发现了华点!

4D476F7F-39A1-4E42-B374-8642D195B1B0.png

可以看到 refreshToken 竟然是空的???我立马登上从库查了一下,发现有数据的啊!!

6469CCA9-5FF3-41A2-AFED-632750B1C3A0.png

麻了,我又麻了,所以发生什么事了??

我立马去检查了刷新 token 任务的代码,确认了我的 sql 确实会获取 refreshToken ,既然数据库里有值,那我可以“断定”我去刷新任务的时候 refreshToken 肯定不为空!

而突然,我发现这个获取是有缓存的!

ED956132-3017-446C-9F1A-95B6BC656FC6.png

就灵光这么一闪,我立马去查看缓存,发现缓存里的 refreshToken 竟然是空的,我想难道是哪个兔崽子把缓存中的 refreshToken 删了。

604488F3-21F3-4D45-BBB1-C92951E0EAB7.png

随即,我就否认了这个想法,我们应该不可能有这种需求和实现....


没啥思路,我去看了看公司内部工具调用获取 token 的代码,发现是调用的是一个 rpc 接口,由于我没有那个服务的代码,于是就去问一位老同事,他有点印象,来了句:

0547F30A-E70E-4AF6-9F0F-4BBCD791F6B8.png


好嘛,被我逮到了,直接跟修改过的那位同事进行一个对线,谁知对方只回了三个字:

755589B2-9DF4-4992-8CFE-58AD22CDC179.png


我直接一个:

0A766D3A-076F-4FC4-AEF3-590A981B2619.png


至此是破案了....


这位同事的思路是这样的:他认为平日里获取 token 是不需要用到 refreshToken 的,所以出于 select 啥拿啥的规则,他选择了不拿 refreshToken,这么一来切面的缓存塞入里就没塞 refreshToken 值。

然后授权服务是最开始写的,那时候还未抽离出这位同事负责的服务 A,因此关于 token 的获取和写入都是授权服务自身操作数据库实现的,所以我很确定我的代码确实从数据库拿 refreshToken ,压根就不会想到 refreshToken 会是空。

问题就出在两者共用了一个缓存 key ,服务 A 出于节省原则,获取用户授权信息的时候并未在缓存里塞入 refreshToken ,这导致授权服务去获取用户授权信息时,由于命中了缓存,直接从缓存里拿值,而缓存里并没有 refreshToken 的值,所以调用第三方刷新 token 接口的时候, refreshToken 传的值是空!

所以第三方返回了一个错:

D9283BC8-097E-48A4-9F9B-D4FE9CF4513A.png

至此,我才明白这个缺少 code 的含义....我想说报错信息返回 refreshToken 参数为空不香吗,给我整个 code,我都不知道是啥 code!然后,对于那些授权服务先于服务 A 塞入缓存的用户来说,他们的刷新授权是正常的,因为授权服务会把 refreshToken 塞到缓存中。

好了,排查完毕,最终的处理方式是服务 A 也将 refreshToken 塞到缓存中。

最后

可以看到,这次的排查其实不涉及到什么高深的技术,其实就是多方联动,且考虑不周导致的错误。其实生产环境大部分出错都是一些细节问题,例如参数配置的不对啊,多写了一个判断等等。


我们来小结一下这次的经历:

  • 数据的获取要考虑缓存的正确性,不能仅以数据库为准,不要忘了缓存
  • 收敛服务的操作,即服务划分清晰独立,尽量不要在内部实现其他服务的功能,这样在需求变更时可以避免多改和漏改,也不会发生上述的问题,统一约束,最为舒服
  • 报错信息清晰,像上面的报错如果不是缺少 code 而是 refreshToken 参数为空,我可能在第一次看到这个报错的时候就排查完了,也不用等到现在(信任值也很重要,出错多了,就渐渐不信任对方的服务)
  • 全局意识很关键。即使你负责只一个服务,有机会也要多了解了解别人的服务,特别是自己的上下游,这样出了问题,脑子能很清晰地扫描全局,快速的定位可能发现问题的地方,这就是大牛和普通人的区别(你处理不了,人家两分钟搞定)。

大致就这么多了,如果你有需求,也可以把这段经历拿去面试用,哈哈哈,不用跟我客气!

我是yes,从一点点到亿点点,让我们一起期待下次的线上排查!

点赞收藏
分类:标签:
yes的练级攻略

公众号【yes的练级攻略】,专注分享后端技术

请先登录,查看3条精彩评论吧
快去登录吧,你将获得
  • 浏览更多精彩评论
  • 和开发者讨论交流,共同进步

为你推荐

日常Bug排查-偶发性读数据不一致

日常Bug排查-偶发性读数据不一致

7
3