背景:
五一休假最后一天，发现es集群开始cpu告警，找到大盘一看，一个节点产生cpu彪升；随着查询量的上升，cpu抖动的比较厉害；之前产生过一次，当时没有排查到具体原因，重启单节点之后就恢复了，因此联系dba进行节点重启；dba重启后，发现第二天还是存在这个问题，但是没有之前彪升的厉害，怀疑是重启过快导致的分片没有rebalance导致；因此dba建议重新再重启一次，最后一次重启后，擦，还存在这个问题；ok。排除了分片不均匀、热点数据不均匀导致的问题；应该是一个频发的问题，着重在代码层进行性能分析。
当时的集群监控图是这样的
问题定位:
由于是单节点问题【后期发现已经不再是单节点的表现了】；因此选取当时的节点抓取节点上的task，和对应的hotThread进行性能分析；
task日志:
"XhNJ0SxFTWmuL3VuUe0YWQ"
: {
"name"
:
"XXXX-16"
,
"transport_address"
:
"xx.xxx.16.60:9300"
,
"host"
: "xx.xxx.16.60",
"ip"
: "xx.xxx.16.60:9300",
"roles"
: [
"ingest"
,
"master"
,
"data"
,
"ml"
],
"attributes"
: {
"ml.machine_memory"
:
"66310864896"
,
"ml.max_open_jobs"
:
"20"
,
"xpack.installed"
:
"true"
},
"tasks"
: {
"XhNJ0SxFTWmuL3VuUe0YWQ:21045201"
: {
"node"
:
"XhNJ0SxFTWmuL3VuUe0YWQ"
,
"id"
:
21045201
,
"type"
:
"transport"
,
"action"
:
"indices:data/read/search[phase/query]"
,
"description"
:
"shardId[[XXX_index][18]]"
,
"start_time_in_millis"
:
1620287544319
,
"running_time_in_nanos"
:
223057300
,
"cancellable"
:
true
,
"parent_task_id"
:
"FhKJs8q5RF-9EuFAf51KmQ:5221102531"
,
"headers"
: { }
},
"XhNJ0SxFTWmuL3VuUe0YWQ:21045200"
: {
"node"
:
"XhNJ0SxFTWmuL3VuUe0YWQ"
,
"id"
:
21045200
,
"type"
:
"transport"
,
"action"
:
"indices:data/read/search[phase/query]"
,
"description"
: "shardId[[XXX_index][17]]",
"start_time_in_millis"
:
1620287544319
,
"running_time_in_nanos"
:
223123798
,
"cancellable"
:
true
,
"parent_task_id"
:
"FhKJs8q5RF-9EuFAf51KmQ:5221102531"
,
"headers"
: { }
}
}
}
|
hotThread日志:
查看hotThread的api:
GET /_nodes/<node_id>/hot_threads
从task日志上可以看到，目前16节点主要处理的是来自于xxx_index这个索引的请求；而hotThread里面看到的是大量cpu消耗再PointRangeQuery上面；
拉取kinbana日志查看16节点关于xxx_index的慢查询日志;拉取到这样一条慢查询日志
{
"from"
:
0
,
"size"
:
50
,
"timeout"
:
"1s"
,
"query"
: {
"bool"
: {
"must"
: [{
"bool"
: {
"must"
: [{
"term"
: {
"fileld1"
: {
"value"
:
25903048444465
,
"boost"
:
1.0
}
}
}, {
"term"
: {
"fileld2": {
"value"
:
0
,
"boost"
:
1.0
}
}
}, {
"term"
: {
"fileld3": {
"value"
:
1
,
"boost"
:
1.0
}
}
}],
"adjust_pure_negative"
:
true
,
"boost"
:
1.0
}
}],
"adjust_pure_negative"
:
true
,
"boost"
:
1.0
}
},
"_source"
: {
}
}
|
通过profiler进行性能分析，查看性能损耗在什么地方
可以看到 大部分的性能损耗在构建两个PointQuery上面，这个和我们之前看到的hotThread中的性能损耗相互印证了；
但是为啥会有PointRangeQuery呢？查看mapping发现，fileld2和fileld3字段是numer类型，number类型在查询的时候会转换成Range查询，尽管我们并不需要；
为啥Range查询会又这么大的性能损耗呢？普通的Range查询并不会又这么大的range损耗，只有在字段筛选度不够的情况下，才会产生大的性能损耗；本质原因是会进行根据range筛选出的结果集在内存中构建bitset,比较消耗cpu
由于我们是匹配条件来进行查询的，因此我们不需要使用Range进行查询，只需要使用term进行查询即可；
因此解决方案:
1.fileld2和fileld3字段 新增一个keyWord类型的字段，我们进行term查询
临时解决方案：
查询了一下fileld2字段全是1，因此可以不作为入参条件，这样的话，能临时提供一部分性能，支撑到数据刷取结束，替换成keyWord;
问题解决:
去除fileld2查询条件；
问题验证:
上线之后，第二天cpu如下：
反向验证一波，是我们优化起效果了，关闭优化开关，还原查询：
总结:
此次的ES问题定位花费了比较长的时间，最终算是有一个结果；最大的感触是，坚持到底，不断抽丝剥茧，在定位中学习、成长；终究会有收获；
相关参考资料：
https://blog.csdn.net/ahwsk/article/details/104657123
https://www.elastic.co/cn/blog/better-query-planning-for-range-queries-in-elasticsearch
https://www.elastic.co/cn/blog/elasticsearch-query-execution-order
