使用 dmesg 来查看一些硬件或驱动程序的信息或问题。

elasticsearch每个shard的查询很快,但是总响应时间很长,不知道耗时在哪个步骤上

Elasticsearch | 作者 matt_jn | 发布于2020年06月03日 | 阅读数:373

环境信息 


elasticsearch5.6.16,集群5个节点,每个节点(16核,64G内存,1T SSD存储),Elasticsearch堆启动内存24GB


数据量


按月建索引,每个索引150G,3亿文档(不包含副本),5个主shard,2个副本
 


问题描述:


5个shard,每个shard的查询时间大概在1百毫秒级,但查询响应时间在5秒以上


 索引Mapping:
{
"properties": {
"EventId": {
"type": "keyword"
},
"Time": {
"type": "long"
},
"SourceId": {
"type": "keyword"
},
"Severity": {
"type": "integer"
},
"Message": {
"type": "text",
"norms": false,
"index_options": "docs"
},
"Area1": {
"type": "keyword"
},
"Site": {
"type": "keyword"
}
}
}

查询DSL
{
"profile":true,
"from": 0,
"size": 2000,
"query": {
"bool": {
"filter": [{
"range": {
"Time": {
"gte": 1564934400000,
"lte": 1565020800000
}
}
},
{
"term": {
"Area1": "ns=9310;s=POW.arAlHjOD"
}
},
{
"range": {
"Severity": {
"from": 0,
"to": 100
}
}
},
{
"match": {
"Message": "alarm"
}
}
],
"must_not": [{
"term": {
"Site": "ns=9490;s=PWE.iFjpfTWp"
}
}]
}
},
"sort": [{
"Time": {
"order": "desc"
}
},
{
"EventId": {
"order": "desc"
}
}]
}

 

 查询结果:
{
"took": 5103,
"timed_out": false,
"_shards": {
"total": 5,
"successful": 5,
"skipped": 0,
"failed": 0
},
"hits": {
"total": 1975,
"max_score": null,
"hits": [.......]
},
"profile": {
"shards": [{
"id": "[PmkW-Sw-ThOLEmwpSeMMlA][events-history-201909][1]",
"searches": [{
"query": [{
"type": "BooleanQuery",
"description": "-Site:ns=9490;s=PWE.iFjpfTWp #Time:[1569345000000 TO 1569431400000] #Area1:ns=9310;s=POW.arAlHjOD #Severity:[0 TO 100] #Message:alarm",
"time": "45.83703800ms",
"time_in_nanos": 45837038,
"children": [{
"type": "TermQuery",
"description": "Site:ns=9490;s=PWE.iFjpfTWp",
"time": "0.7859000000ms",
"time_in_nanos": 785900,

},
{
"type": "IndexOrDocValuesQuery",
"description": "Time:[1569345000000 TO 1569431400000]",
"time": "64.51731000ms",
"time_in_nanos": 64517310,

},
{
"type": "TermQuery",
"description": "Area1:ns=9310;s=POW.arAlHjOD",
"time": "2.630864000ms",
"time_in_nanos": 2630864,

},
{
"type": "IndexOrDocValuesQuery",
"description": "Severity:[0 TO 100]",
"time": "2.076803000ms",
"time_in_nanos": 2076803,

},
{
"type": "TermQuery",
"description": "Message:alarm",
"time": "2.590450000ms",
"time_in_nanos": 2590450,

}]
}],
"rewrite_time": 10471,
"collector": [{
"name": "CancellableCollector",
"reason": "search_cancelled",
"time": "1.285638000ms",
"time_in_nanos": 1285638,

}]
}],
"aggregations":
},
{
"id": "[PmkW-Sw-ThOLEmwpSeMMlA][events-history-201909][2]",
"searches": [{
"query": [{
"type": "BooleanQuery",
"description": "-Site:ns=9490;s=PWE.iFjpfTWp #Time:[1569345000000 TO 1569431400000] #Area1:ns=9310;s=POW.arAlHjOD #Severity:[0 TO 100] #Message:alarm",
"time": "18.19332900ms",
"time_in_nanos": 18193329,
"children": [{
"type": "TermQuery",
"description": "Site:ns=9490;s=PWE.iFjpfTWp",
"time": "0.5694900000ms",
"time_in_nanos": 569490,

},
{
"type": "IndexOrDocValuesQuery",
"description": "Time:[1569345000000 TO 1569431400000]",
"time": "2.403989000ms",
"time_in_nanos": 2403989,

},
{
"type": "TermQuery",
"description": "Area1:ns=9310;s=POW.arAlHjOD",
"time": "12.52754700ms",
"time_in_nanos": 12527547,

},
{
"type": "IndexOrDocValuesQuery",
"description": "Severity:[0 TO 100]",
"time": "1.327001000ms",
"time_in_nanos": 1327001,

},
{
"type": "TermQuery",
"description": "Message:alarm",
"time": "1.660747000ms",
"time_in_nanos": 1660747,

}]
}],
"rewrite_time": 5156,
"collector": [{
"name": "CancellableCollector",
"reason": "search_cancelled",
"time": "1.262665000ms",
"time_in_nanos": 1262665,

}]
}],
"aggregations":
},
{
"id": "[cB5z4kUSTYaYam5XUGcPmA][events-history-201909][0]",
"searches": [{
"query": [{
"type": "BooleanQuery",
"description": "-Site:ns=9490;s=PWE.iFjpfTWp #Time:[1569345000000 TO 1569431400000] #Area1:ns=9310;s=POW.arAlHjOD #Severity:[0 TO 100] #Message:alarm",
"time": "116.4847370ms",
"time_in_nanos": 116484737,
"children": [{
"type": "TermQuery",
"description": "Site:ns=9490;s=PWE.iFjpfTWp",
"time": "0.5082780000ms",
"time_in_nanos": 508278,

},
{
"type": "IndexOrDocValuesQuery",
"description": "Time:[1569345000000 TO 1569431400000]",
"time": "35.07663200ms",
"time_in_nanos": 35076632,

},
{
"type": "TermQuery",
"description": "Area1:ns=9310;s=POW.arAlHjOD",
"time": "62.93598600ms",
"time_in_nanos": 62935986,

},
{
"type": "IndexOrDocValuesQuery",
"description": "Severity:[0 TO 100]",
"time": "1.492956000ms",
"time_in_nanos": 1492956,

},
{
"type": "TermQuery",
"description": "Message:alarm",
"time": "1.748266000ms",
"time_in_nanos": 1748266,

}]
}],
"rewrite_time": 5547,
"collector": [{
"name": "CancellableCollector",
"reason": "search_cancelled",
"time": "1.763664000ms",
"time_in_nanos": 1763664,

}]
}],
"aggregations":
},
{
"id": "[hJ6tl3mvSHiyJrI2H_foFQ][events-history-201909][3]",
"searches": [{
"query": [{
"type": "BooleanQuery",
"description": "-Site:ns=9490;s=PWE.iFjpfTWp #Time:[1569345000000 TO 1569431400000] #Area1:ns=9310;s=POW.arAlHjOD #Severity:[0 TO 100] #Message:alarm",
"time": "43.90771200ms",
"time_in_nanos": 43907712,
"children": [{
"type": "TermQuery",
"description": "Site:ns=9490;s=PWE.iFjpfTWp",
"time": "0.5759190000ms",
"time_in_nanos": 575919,

},
{
"type": "IndexOrDocValuesQuery",
"description": "Time:[1569345000000 TO 1569431400000]",
"time": "46.78477100ms",
"time_in_nanos": 46784771,

},
{
"type": "TermQuery",
"description": "Area1:ns=9310;s=POW.arAlHjOD",
"time": "1.522379000ms",
"time_in_nanos": 1522379,

},
{
"type": "IndexOrDocValuesQuery",
"description": "Severity:[0 TO 100]",
"time": "1.848593000ms",
"time_in_nanos": 1848593,

},
{
"type": "TermQuery",
"description": "Message:alarm",
"time": "2.170097000ms",
"time_in_nanos": 2170097,

}]
}],
"rewrite_time": 11487,
"collector": [{
"name": "CancellableCollector",
"reason": "search_cancelled",
"time": "4.127291000ms",
"time_in_nanos": 4127291,

}]
}],
"aggregations":
},
{
"id": "[uvVmQP6FTqubRRszz4ubIA][events-history-201909][4]",
"searches": [{
"query": [{
"type": "BooleanQuery",
"description": "-Site:ns=9490;s=PWE.iFjpfTWp #Time:[1569345000000 TO 1569431400000] #Area1:ns=9310;s=POW.arAlHjOD #Severity:[0 TO 100] #Message:alarm",
"time": "59.86074200ms",
"time_in_nanos": 59860742,
"children": [{
"type": "TermQuery",
"description": "Site:ns=9490;s=PWE.iFjpfTWp",
"time": "0.5899410000ms",
"time_in_nanos": 589941,

},
{
"type": "IndexOrDocValuesQuery",
"description": "Time:[1569345000000 TO 1569431400000]",
"time": "63.97123300ms",
"time_in_nanos": 63971233,

},
{
"type": "TermQuery",
"description": "Area1:ns=9310;s=POW.arAlHjOD",
"time": "1.385124000ms",
"time_in_nanos": 1385124,

},
{
"type": "IndexOrDocValuesQuery",
"description": "Severity:[0 TO 100]",
"time": "1.828161000ms",
"time_in_nanos": 1828161,

},
{
"type": "TermQuery",
"description": "Message:alarm",
"time": "1.892925000ms",
"time_in_nanos": 1892925,

}]
}],
"rewrite_time": 5311,
"collector": [{
"name": "CancellableCollector",
"reason": "search_cancelled",
"time": "1.171450000ms",
"time_in_nanos": 1171450,

}]
}]
}]
}
}
已邀请:

locatelli

赞同来自: byx313

profile不计算网络开销,不计算在coordinating节点上做合并的开销以及其它一些在队列里的等待时间等等。
 

byx313 - BLOG:https://www.jianshu.com/u/43fd06f9589c

赞同来自:

不大清楚profile的说明,但是看里面是没有加上sort的耗时的,我猜测可能是sort慢了。又或者是你的单个doc的size很大,导致网络传输慢了。

hnj1575565068 - 90后

赞同来自:

建议你的查询加一下路由吧,现在查的是很多个分片

zwwlouis

赞同来自:

1、首先要明白一点,profile的时间是不准的,由于逐个计时过于耗时,所以profile的时间实际上使用了采样的方式来进行估计。
2、其次,profile的时间并不包括fetch time,也就是去磁盘中取文档内容的时间。索引可以被提前加载在内存中加速查找,但是索引里面存储的只有文档的地址信息,文档的具体内容需要根据地址去磁盘中提取,这个过程极其依赖磁盘性能。尤其是size比较大的时候,这部分的耗时可能会占绝大部分。

要回复问题请先登录注册