一、好言
这世上只有一种成功,叫:"用自己喜欢的方式过一生。"
二、背景
公司运营最近做活动,但是在早上发现统计的转换率低的吓人,因此开发就开始找问题,主要是很多用户没有看到造成的,这就涉及到后台排查问题,结果是由于dubbo接口调用超时,基本上每个接口调用都是超过60s的,这。。。,所以。。。
三、问题及解决
上午快吃饭的时候才被通知处理这个线上事故原因,当然首先就是查询日志了,我们的日志做了统一的处理的,所以就开始查询出现问题的时间点,查询错误日志,一看这个接口的调用都是超时,那么就有如下情况:
(1):这个接口内部业务逻辑太多需要优化代码。
(2):数据库查询消耗太多时间。
对于(1)的话,因为之前运行的挺好的,虽然的确业务复杂,但是代码层面还不至于超时到60s都没反应。所以我果断的就查看了这个方法里面的用到的数据库表,表的数据量是否太大,查询条件是否建立了索引,结果发现,用到了三个表,两个表在mysql上,一个在Mongodb上。mysql上的表,一张表数据量不到100w,一张表的数据不到10条,并且多的那张表是有索引的。所以现在就剩下mongodb,这可就完了,我没怎么折腾过mongodb,但是还是把有关mongodb那部分的代码看了看,最后查看日志,在一个先删除后新增哪里,删除报错,但是写代码的同事捕获异常,但是也打印了日志,但是没有把错误日志打出来。所以就找dba了,dba的说的是早上六点多的时候mongodb挂了,连接池爆了,到现在,基本定位问题是mongodb问题,但是看了下连接数一直都是1w多个,最后用mongotop监测,发现这1w多个都是挂着的进程,mongodb的进程执行不完,我看了下数据量,总共才80w左右的数据量,为啥删除这里就这么慢,大量累积了,最后发现是没有建立索引,删除时候锁表,每次删除一条数据好慢,造成大量连接请求大量累积。最后按照条件建立索引后,原本等着1W多个请求执行完建立索引,但是后来发现连接一直保持在8k左右,就强制杀掉了,建立好索引后,连接数保持正常数量在1-2k之间。并且相应的推广页面也能在手机上显示。
之前那个mysql问题也是,自己测试很好,但是一到生产上,由于生产的数据量大,并且不易清理,所以对于一些不建立索引,又经常用到的,那将造成查询,修改等超时问题。避免锁整个表,影响性能。
cause: Waiting server-side response timeout by scan timer. start time: 2017-05-25 14:30:34.619, end time:
2017-05-21 14:31:34.639, client elapsed: 0 ms, server elapsed: 60020 ms, timeout: 60000 ms, request:
Request [id=11396, version=2.0.0, twoway=true, event=false, broken=false, data=RpcInvocation
[methodName=selectPersonByCondition, parameterTypes=[class
com.test.moon.mouse.model.dto.QueryDto], arguments=
[com.test.moon.mouse.model.dto.QueryDto@12fv4