ES6.8.3 节点突然宕机原因分析?iowait 突然变高、load突然变高,get/write/search/flush 线程全部blocked
Elasticsearch | 作者 hapjin | 发布于2019年12月06日 | 阅读数:4927看:dump到logs/目录下的日志文件 hs_err_pid51792.log 发现:
所有的get/search/write/flush 等线程状态都是thread_blocked,示例如下:
0x00007f41d4027000 JavaThread "elasticsearch[node-140][get][T#3]" daemon [_thread_blocked, id=53837, stack(0x00007f3a116d5000,0x00007f3a117d6000)]
0x00007f41d801f000 JavaThread "elasticsearch[node-140][search][T#31]" daemon [_thread_blocked, id=53819, stack(0x00007f3a127e4000,0x00007f3a128e5000)]
0x00007f424c00f800 JavaThread "elasticsearch[node-140][write][T#20]" daemon [_thread_blocked, id=53820, stack(0x00007f3a126e3000,0x00007f3a127e4000)]
然后,hs_err_pid51792.log记录的内存使用信息/proc/meminfo 如下:
MemTotal: 65636320 kB
MemFree: 2061864 kB
MemAvailable: 27202812 kB
Buffers: 508840 kB
Cached: 24419920 kB
SwapCached: 1132 kB
Active: 4631072 kB
Inactive: 23532464 kB
Active(anon): 2459300 kB
Inactive(anon): 803420 kB
Active(file): 2171772 kB
Inactive(file): 22729044 kB
Unevictable: 33760664 kB
Mlocked: 33760664 kB
SwapTotal: 7813116 kB
SwapFree: 7802244 kB
Dirty: 4312 kB
Writeback: 8 kB
AnonPages: 36984168 kB
Mapped: 939104 kB
Shmem: 4172 kB
Slab: 1098584 kB
SReclaimable: 909480 kB
SUnreclaim: 189104 kB
KernelStack: 14720 kB
PageTables: 88036 kB
NFS_Unstable: 0 kB
Bounce: 0 kB
WritebackTmp: 0 kB
CommitLimit: 40631276 kB
Committed_AS: 39350236 kB
VmallocTotal: 34359738367 kB
VmallocUsed: 0 kB
VmallocChunk: 0 kB
HardwareCorrupted: 0 kB
AnonHugePages: 34211840 kB
其中:MemTotal是65636320KB,MemFree是2061864KB,MemAvailable是27202812KB,CommitLimit是40631276KB。
操作系统参数:/proc/sys/vm/overcommit_memory 的值是0,说明是允许 overcommit的。
/etc/sysctl.conf 里面的参数 vm.swappiness = 10,可能会有发生内存交换()
MemTotal 减去 MemFree 已经远远大于 CommitLimit ,因此是不是 可以推断ES进程被Linux oom killer 给杀死了?
但是 MemTotal 减去 MemAvailable 是小于 CommitLimit 的,并且我看操作系统日志 /var/log/messages、/var/log/kern.log 里面都没有相应的记录 显示 ES进程被 Linux oom killer 给杀死了。
另外,如果有大神指点一下:MemFree 和 MemAvailable 二者之间的差别就更好了(我的理解就是:MemAvailable 还包括了那些已经被使用了但是可以被回收的内存空间,所以 MemAvailable 一般都比MemFree大)
如果不是被Linux oom killer 给干掉了,那ES进程是因为什么原因挂掉了呢?
hs_err_pid51792.log 中有最近10次的GC情况,其中1次如下:
GC Heap History (10 events):
Event: 895949.541 GC heap before
{Heap before GC invocations=6751 (full 2):
par new generation total 1380160K, used 1264527K [0x00007f4340000000, 0x00007f439d990000, 0x00007f439d990000)
eden space 1226816K, 100% used [0x00007f4340000000, 0x00007f438ae10000, 0x00007f438ae10000)
from space 153344K, 24% used [0x00007f43943d0000, 0x00007f43968a3d40, 0x00007f439d990000)
to space 153344K, 0% used [0x00007f438ae10000, 0x00007f438ae10000, 0x00007f43943d0000)
concurrent mark-sweep generation total 30972352K, used 9007531K [0x00007f439d990000, 0x00007f4b00000000, 0x00007f4b00000000)
Metaspace used 88568K, capacity 97291K, committed 97464K, reserved 1132544K
class space used 11381K, capacity 13797K, committed 13920K, reserved 1048576K
Event: 895949.604 GC heap after
Heap after GC invocations=6752 (full 2):
par new generation total 1380160K, used 37437K [0x00007f4340000000, 0x00007f439d990000, 0x00007f439d990000)
eden space 1226816K, 0% used [0x00007f4340000000, 0x00007f4340000000, 0x00007f438ae10000)
from space 153344K, 24% used [0x00007f438ae10000, 0x00007f438d29f4b8, 0x00007f43943d0000)
to space 153344K, 0% used [0x00007f43943d0000, 0x00007f43943d0000, 0x00007f439d990000)
concurrent mark-sweep generation total 30972352K, used 9008635K [0x00007f439d990000, 0x00007f4b00000000, 0x00007f4b00000000)
Metaspace used 88568K, capacity 97291K, committed 97464K, reserved 1132544K
class space used 11381K, capacity 13797K, committed 13920K, reserved 1048576K
}
其他几次的GC与上面类似,都是Eden区使用100%之后发生了GC。看gc.log.0.current 里面的日志,stop time 大都在几十ms,偶尔有几百毫秒的停顿。机器是4核64GB内存的机器,ES配置文件jvm.options配置如下:
-Xms31g
-Xmx31g
-XX:+UseConcMarkSweepGC
-XX:CMSInitiatingOccupancyFraction=75
-XX:+UseCMSInitiatingOccupancyOnly
然后,因为在故障时间点前一段时间上线了一个程序,大量写ES,看了下机器监控,发现cpu iowait 涨到250、4核cpu的节点负载涨到了60。内存的使用率一直在60%左右(在发生故障前,监控到内存使用一直很稳定,并且cpu的利用率一直都不高,3%左右)。
所以我觉得应该不是内存导致的ES进程挂掉,而是大量的写操作,使得磁盘响应不过来,最终导致ES进程挂掉的。但是为什么 所有的线程都 blocked 了呢?如果进程不是因为OOM挂掉,那又具体是什么原因导致进程挂掉了呢?
cpu_iowait:
iowait Show the percentage of time that the CPU or CPUs were idle during which the system had an outstanding disk I/O request.
load:
diskIOutil
memory(监控到的机器内存使用,一直都是使用了60%,然后在12月5号晚上8点40的样子,ES进程挂了,所以内存使用一下子跌下去了)
[/quote]
完整的dump hs_err 文件见附件,user_profile-2019-12-05-1.log 是ElasticSearch节点运行打印出来的日志。JDK版本,OS版本如下:
java version "1.8.0_161"
Java(TM) SE Runtime Environment (build 1.8.0_161-b12)
Java HotSpot(TM) 64-Bit Server VM (build 25.161-b12, mixed mode)
Linux ubuntu 4.9.0-39-custom #12 SMP Sat Jul 22 13:14:22 CST 2017 x86_64 x86_64 x86_64 GNU/Linux
4 个回复
cyberdak
赞同来自:
看你这种情况其实更像 linux timeout 120s ,不过要等看完日志以后才能确定,所幸dmesg也能看到timeout 的日志
easyice - 张超
赞同来自:
easyice - 张超
赞同来自:
如果问题可以重现,可以升级 JDK 试下,或者关闭 JIT,禁用动态编译
匿名用户
赞同来自:
所以,一般情况,cpu核心最少要20核心,40线程以上。
如果可能,请使用40核心80线程的物理机。
内存64gb
硬盘,10tb,能用ssd就用,别用普通硬盘
网卡能用万兆别用千兆。
当你硬件升级后,你就会发现,你所有的问题,全没了。