一次高并发抢购活动引起的生产事故的过程分析记录

1.在日志中观察到的很多dubbo超时报错

Caused by: com.alibaba.dubbo.remoting.TimeoutException: Waiting server-side response timeout. 

排查过程:数据库sql负载偏高,有接口直接查sql没有加缓存的,数据库瓶颈没办法,一个sql延迟几十毫秒,并发上来之后,就会把整体往后拖了

原因分析:

1.执行sql没有超时时间,慢就慢了,但是rpc接口和对外接口是有timeout的,单个dubbo服务是的线程池数量是有上限的,

2.每个rpc接口调用1个sql,一个sql延迟100ms,就算一个rpc调用100ms,比如这个进程给的线程数是100,那么一秒钟1000ms/200ms * 100 = 500次,也就是这个rpc接口的性能是500次/秒,恰好能够没有线程阻塞等待处理完毕,当501并发时第501个就会阻塞100ms才能进到rpc中执行代码处理,最后因为sql的超时导致了调用dubbo provider进程阻塞,继而导致rpc外层调用的consumer超时,接口返回异常。

将sql全部优化之后,发现在高并发的时候日志中还是有超时的报错,看问题还是一样的,最后排查发现是因为A服务对外提供了一个按id查唯一信息的rpc接口,B服务中有逻辑为了获取多个id的信息,循环进行多次rpc调用。所以如果B服务获取的id信息越多对应的rpc循环调用的次数也就越多,从而B的这个业务操作会更加耗时,最后导致超时问题的出现。

最后把这里优化掉,改成一次rpc调用从A服务中批量拿到全部的数据后再在B服务这里分组依次获取。 

2.修复上面的问题后发现又出现了dubbo线程池满了的报错

\[DUBBO\] Thread pool is EXHAUSTED! Thread Name: DubboServerHandler-ip:70882, Pool Size: 400 (active: 400, core: 400, max: 400, largest: 400), Task: 8640430 (completed: 8640030), Executor status:(isShutdown:false, isTerminated:false, isTerminating:false), in dubbo://ip:70882!, dubbo version: 2.6.2, current host: ip

dubbo线程池满了,我们通过重新设置线程池大小dubbo.provider.threads = 1000

3.调大线程池后又出现了另外一个问题,Redis连接数跑满了

org.springframework.data.redis.RedisConnectionFailureException: No reachable node in cluster; nested exception is redis.clients.jedis.exceptions.JedisNoReachableClusterNodeException: No reachable node in cluster

redis连接数跑满了,这个问题寻找了好久,最终发现是Jedis的版本问题版本问题,导致链接没有释放,连接泄露,我们通过升级jedis版本到2.10.2就解决了这个问题。

详情见这里https://blog.csdn.net/RL_LEEE/article/details/99831991

4.修复了上面的问题后,又出现了redis连接池跑满了问题

org.springframework.dao.InvalidDataAccessApiUsageException: Could not get a resource since the pool is exhausted; nested exception is redis.clients.jedis.exceptions.JedisExhaustedPoolException: Could not get a resource since the pool is exhausted

redis连接池数量太小了,我们通过增大spring.redis.jedis.pool.max-idle = 100,spring.redis.jedis.pool.max-active = 100,这两个配置重新进行了调整。

5.连接池跑满了的问题解决了,紧接着又出现了热点Key的分布不均匀的问题

redis.clients.jedis.exceptions.JedisClusterMaxRedirectionsException: Too many Cluster redirections?

这个是一个热点大Key的问题,把一个在高峰期会频繁访问的对象全部缓存成一个大对象放到redis里面,最终导致这个对象的大小超过了5MB,因为redis是单线程,每次读取5MB然后再进行传输,会导致网络io上升,并发数上来后,很容易把热点Key所在的节点给压挂。

解决方法就是将整存整取的大对象,分拆为多个小对象。可以尝试将对象分拆成几个key-value, 使用multiGet获取值,这样分拆的意义在于分拆单次操作的压力,将操作压力平摊到多个redis实例中,降低对单个redis的IO影响。

6.最终,将上面的问题都解决了之后事故得以最终解决,特此记录,备忘。

如果对您有帮助,请不要忘了给翎野君点赞。


翎野君
76 声望5 粉丝