记一次系统Dubbo调用超时的故障

现象:生产环境用户无法使用下单,订单无法交易。

异常日志:

分析:

发现订单调用商品的API超时了,登陆商品系统并没有发现任何的异常调用,感觉订单的系统调用并没有抵达商品系统,后来陆续发现订单访问其他系统的Dubbo调用都超时了,由此可断定可能是订单系统的问题。首先想到的是数据库的链接数,查看RDS的连接数:

可以看到,15点开始,总连接数开始飙升,并且临近最大值480(但是一直没到最大值480),但是活跃连接数却始终保持在非常低的水平。可能是由于活动开始,根据之前经验,连接数上升是正常的情况,活动连接数低说明db在获取数据中,并且db的其他性能并没有出现瓶颈情况,iops情况如下:

看了一下rds的性能优化发现有一条慢sql,

但此时重点并没有放在这里。原因如上,

我们认为db没有到达瓶颈(连接池没满,而且iops在正常范围)。

当时我们还查看了db的实时会话,

当时有大量的处于sleep中的语句,

大约有200多个,这说明,

有大量sql连接正在等待mysql返回数据,

这就是iops不高的原因。

上图这是事后正常的截图。

另外一边进行jstack, 查看日志,

发现大量线程处于wait状态:

初步判断应该不竞争锁,

否则出现的应该是

blocked, Locked ownable synchronizers: – None

也说明了这个情况,也没有找到死锁的迹象。

我们查看Mysql的使用情况,

发现200多个实物处于Sleep状态,

但是没能推测出是由于大数据量查询

都处于等待数据的返回。

接下来查看日志里面有

**java.lang.OutOfMemoryError:

Java heap space **,

查看GC的情况,发现系统每5s就进行了一次FullGC,

此时在查看内存情况,

堆内存基本被占满。 继续查看日志,

发现由于一个SQL的query操作引起的,

在跟进这段代码深入分析,

发现这段查询逻辑直接查询数据库,

而且数据量非常大,

每次3W条数据,

大于每个线程需要占用30M的堆内存,

100个连接就需要3G的内存,

但是我们的JVM最大设置的是

2G内存所以导致存储空间不足。

这下明白了,由于堆内存空间不足,

所以任何dubbo的调用都无法正常分配到内存,

所以就导致了任何接口的超时表现。

异常日志中出现 Unable to create new native thread,

出现这个异常的原因、排查方法是什么呢?

根据毕玄的文档:

查看操作系统Linux的最大线程数:

结果是:60949 。

ulimit 用于限制 shell 启动进程所占用的资源,

支持以下各种类型的限制:所创建的内核文件的大小、

进程数据块的大小、Shell 进程创建文件的大小、

内存锁住的大小、

常驻内存集的大小、打开文件描述符的数量、

分配堆栈的最大大小、CPU 时间、

单个用户的最大线程数、

Shell 进程所能使用的最大虚拟内存。

同时,它支持硬资源和软资源的限制。

max user processes Linux

默认限制用户最大的线程数为1024。

那么在本系统中JVM中最大的进程数是多少呢?

Jvm(jdk7)中,

-Xms2g -Xmx2g 未设置Xss

(the stack size for each thread),

影响JVM线程数的因子有堆大小(Xmx)、

每个线程的栈大小(Xss)、

系统最大线程数据数(ulimit -u),

参考:JVM中可生成的最大Thread数量。

未设置Xss,默认值是1M(参考1 、参考2),

至于操作系统上栈大小(ulimit -s)为10M,

这个配置只影响进程的初始线程;

后续用pthread_create创建的线程都可以指定栈大小。

HotSpot VM为了能精确控制Java线程的栈大小,

特意不使用进程的初始线程(primordial thread)

作为Java线程,相关参考:

What the difference between -Xss and -XX:ThreadStackSize is?

Inconsistency between -Xss and -XX:ThreadStackSize in the java launcher

能够创建线程的最大个数的估算公式:

(MaxProcessMemory – JVMMemory – ReservedOsMemory) / (ThreadStackSize) = Number of threads

通过大致计算,xmx=2G、xss=1M,那么4G – 2G – 300M(根据top参数预估) / 1M = 1700 预计可以创建1700个左右的线程,但是受限于ulimit -u :1024的限制,所以最多可以创建1024个进程。 查看Jvm进程当前的进程数:

未做活动是的数量为800,

如果不修改ulimit的值,

这很容易导致线程数超限的问题,

所以建议修改到2000。

总结:

整个问题定位花费了很长时间,起先没有能从订单的错误日志入手,其次,监控信息的缺失,FullGC、内存这么重要的监控指标没能监控起来。所以以后遇到这样的类似的问题应该第一时间查看日志,其次查看各种指标数据CPU、内存、GC、jstack等;其次,在编码上,一定要注意任何的查询是否可能会导致大量数据的返回,如果有这种设计就应该重新设计方案。

-END-

  • 发表于:
  • 原文链接https://kuaibao.qq.com/s/20180612G1O84F00?refer=cp_1026
  • 腾讯「云+社区」是腾讯内容开放平台帐号(企鹅号)传播渠道之一,根据《腾讯内容开放平台服务协议》转载发布内容。

扫码关注云+社区

领取腾讯云代金券

年度创作总结 领取年终奖励