工作小记——请求应用无响应
换工作近半年,忙里偷闲,把这段时间遇到的问题和解决思路记录下来。
title变了,工作职责变了,但是仍然有相当一部分实打实技术相关的工作,让我很开心很安心,这是我喜欢且擅长的部分。
但是同时有点遗憾。因为大部分遇到生产问题,除却需求功能相关的。性能的,突发的,冷僻的,各种问题。研发小伙伴大多两手一摊,“我也不知道为什么”。我常会和他们说,“不知道为什么,研究呀,因为从逻辑上来说不应该这样,既然发生了一定有原因”。收到的回复往往是“还是想不出来”。给出建议说,“看日志吧,看看怎么会这样,日志里会有很多线索的”。收到的答复也永远是“日志里没有”。最后最后最最后,还是我一行行看日志,或者review他们的代码,或者查看开源软件的源码,找到问题的原因。
我真的很想说。“亲,这可是你自己打的日志啊,你自己的代码啊,应该你们比我清楚地多。为什么不好好思考呢,确实不是一般情况,可是真的深挖了,找到原因了,高兴之余,收获颇丰呢。这是积累,是经验,是你自己的知识,是你解决问题的思路,这一切的一切都是宝贵的。工作年限留给你的,真的不应该是重复了又重复了的功能性代码的coding。而应该是更广的知识,疑难杂症的小秘籍,解决问题的能力,优秀的架构设计能力啊~~~”
说了很多题外话,言归正转。
症状:20点07分左右,拼多多返利小程序突然请求各种超时,怎么都点不动,首页就超时。
线索:20点公众号发推文。应该会涌入大量新用户。让运维看了下总体请求量,并不大。应用服务器CPU超高,数据库系统各项负载均不高。
应急:20点21分重启后恢复。
查错:线索实在有限,仅仅只有CPU高,也不知道为什么高。看代码太慢且不容易定位。直接看日志应该会更容易。李志翻了错误日志最后一条是18点打的,就放弃了。我翻业务日志发现:
(1)从20点08分后没有user表内新增用户(新用户需调用微信获取openId与session_key后insert到user表)。
(2)10分到21分重启之间,一句日志都没有。
(3)调用微信获取openId与session_key的请求与结果应该成对出现。通过逐条比对,正常时,请求时间稳定在100毫秒。之后有的要1秒半,甚至3秒。比对不打日志之前最后一条请求与返回,相差30秒之多,更可能他们还不是配对的,最后的返回是之前的请求,那就可能远超30秒。(用新标签打开图片可看清晰版)
(4)检查请求微信部分的代码,发现httpclient超时时间设置为3分钟。且tomcat连接数只未设置,为默认的200个
结论:
- 推文带来大量新用户,都需要请求微信
- 请求外部接口(微信),一直没返回
- 超时时间设置过长(3分钟)
- 连接数只采用了默认的200个,没有调整,很容易被打满
- 导致所有的线程都被Hold住等响应
- 都持有着cpu,没有释放,导致CPU飚高到80以上
- 新来的请求全部超时,就算不是新用户,不用请求微信,也因为在等连接而超时
措施:
- 设置合理的http请求超时时间,5-10s就够了
- 设置tomcat可接受连接数,暂定1000
遗留:也没有完全能解释通,但是现有的证据只能探知到这步了:
- 明明20:10分仍然有返回openId,但是为什么新用户只到08分,当中这些返回为什么没有插到数据库中新建用户?
- 为什么重启应用后,微信这边返回就快了?可能是微信这边11分就恢复了,只是我们这边一直被占用着无法尝试新的
基本是这样了,每一次的问题,每一次寻找问题的过程,每一次找到原因,都是一次难得的成长