Graylog2 / Graylog2/graylog2-server
Slow Elasticsearch Queries since sync 'permission' Checks
- Dominant language
- Java
- Stars
- 8.1k
- Forks
- 1.1k
- Avg merge
- 1d 20h
- Merged PRs (30d)
- 217
Description
The query which is send to ES uses since this PRs ( https://github.com/Graylog2/graylog2-server/pull/6573 / https://github.com/Graylog2/graylog2-server/pull/6651 ) an Terms Query for the Stream Permissions. In Environments with a high amount of streams, data in ES and an 'empty' Stream Selection every allowed stream ID gets listed in the Terms Query.
**_disclosure_**: The given examples were send directly to ES without graylog involved, Graylog was just involved to determine the actual query building in graylog itself.
## Expected Behavior
Fast searches which are not slowed because of slow query.
## Current Behavior
Searches get build like this:
```
{
"from": 0,
"size": 0,
"query": {
"bool": {
"must": [
{
"bool": {
"filter": [
{
"query_string": {
"query": "message:exception",
"fields": [],
"type": "best_fields",
"tie_breaker": 0,
"default_operator": "or",
"max_determinized_states": 10000,
"allow_leading_wildcard": true,
"enable_position_increments": true,
"fuzziness": "AUTO",
"fuzzy_prefix_length": 0,
"fuzzy_max_expansions": 50,
"phrase_slop": 0,
"escape": false,
"auto_generate_synonyms_phrase_query": true,
"fuzzy_transpositions": true,
"boost": 1
}
},
{
"match_all": {
"boost": 1
}
}
],
"adjust_pure_negative": true,
"boost": 1
}
},
{
"range": {
"timestamp": {
"from": "2020-10-18 15:24:05.093",
"to": "2020-10-19 15:24:05.093",
"include_lower": true,
"include_upper": true,
"boost": 1
}
}
},
{
"terms": {
"streams": [
"000000000000000000000001",
"000000000000000000000002",
"000000000000000000000003"
],
"boost": 1
}
}
],
"adjust_pure_negative": true,
"boost": 1
}
},
"aggregations": {
"agg-1": {
"date_histogram": {
"field": "timestamp",
"format": "date_time",
"interval": "30m",
"offset": 0,
"order": {
"_key": "asc"
},
"keyed": false,
"min_doc_count": 0
}
},
"timestamp-min": {
"min": {
"field": "timestamp"
}
},
"timestamp-max": {
"max": {
"field": "timestamp"
}
}
}
}
```
Terms directive is in my example 120 streams, I cleaned the IDs out, because in another Env this IDs would not match. Just add your own IDs in the Terms directive.
This Search took first time:
````
{
"took": 11012,
"timed_out": false,
"_shards": {
"total": 605,
"successful": 605,
"skipped": 355,
"failed": 0
},
"hits": {
"total": 3170077,
"max_score": 0,
"hits": [ ]
},`
second time:
`{
"took": 8718,
"timed_out": false,
"_shards": {
"total": 605,
"successful": 605,
"skipped": 355,
"failed": 0
},
"hits": {
"total": 3170077,
"max_score": 0,
"hits": [ ]
},
"aggregations": {
````
The same query without the Terms aggregation finishes in 3 seconds and in the second attempt (proably cached) in 100ms.
If we built one global filter query the results are fixer too:
Query:
````
{
"from": 0,
"size": 0,
"query": {
"bool": {
"must": [
{
"bool": {
"filter": [
{
"query_string": {
"query": "message:exception AND (streams:000000000000000000000001 OR streams:000000000000000000000002 OR streams:000000000000000000000003)",
"fields": [],
"type": "best_fields",
"tie_breaker": 0,
"default_operator": "or",
"max_determinized_states": 10000,
"allow_leading_wildcard": true,
"enable_position_increments": true,
"fuzziness": "AUTO",
"fuzzy_prefix_length": 0,
"fuzzy_max_expansions": 50,
"phrase_slop": 0,
"escape": false,
"auto_generate_synonyms_phrase_query": true,
"fuzzy_transpositions": true,
"boost": 1
}
},
{
"match_all": {
"boost": 1
}
}
],
"adjust_pure_negative": true,
"boost": 1
}
},
{
"range": {
"timestamp": {
"from": "2020-10-18 15:24:05.093",
"to": "2020-10-19 15:24:05.093",
"include_lower": true,
"include_upper": true,
"boost": 1
}
}
}
],
"adjust_pure_negative": true,
"boost": 1
}
},
"aggregations": {
"agg-1": {
"date_histogram": {
"field": "timestamp",
"format": "date_time",
"interval": "30m",
"offset": 0,
"order": {
"_key": "asc"
},
"keyed": false,
"min_doc_count": 0
}
},
"timestamp-min": {
"min": {
"field": "timestamp"
}
},
"timestamp-max": {
"max": {
"field": "timestamp"
}
}
}
}
````
Here again insert your own Stream IDs!
Result comes as follow:
```
{
"took": 1168,
"timed_out": false,
"_shards": {
"total": 605,
"successful": 605,
"skipped": 355,
"failed": 0
},
"hits": {
"total": 3170077,
"max_score": 0,
"hits": [ ]
},
"aggregations": {
```
## Possible Solution
Do not know exactly. Faster but ugly solution would be to chain the stream IDs with an 'OR'
e.g. sth like above.
## Steps to Reproduce (for bugs)
1. Create high amount of streams
2. Search without stream selection and permission granted to nearly all streams
3. watch thread pools for search in ES /_cat/thread_pool/search?v&s=node_name
4. Thread Pool for search is used very much with just one query.
## Context
The Terms query seems to start a internal ES search for every Term given in the Terms query. This is observed using the ES endpoint for search Threadpools (/_cat/thread_pool/search?v&s=node_name) Which results in high used search thread_pools and a slow search result.
## Your Environment
* Graylog Version: 3.3.8
* Java Version: 8
* Elasticsearch Version: 6.8.10 with JDK 11
* MongoDB Version: %%
* Operating System: RHEL
* Browser version: %%
About 30-40TB in ES Cluster and nearly all streams pointing to the same index set
Contributor guide
Assessment
This issue has not been assessed yet.