Graylog2 / Graylog2/graylog2-server

Slow Elasticsearch Queries since sync 'permission' Checks

Open
#9,328 7 comments 0 reactions 1 assignee Claimed by @dennisoelkers View on GitHub
bug triaged
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

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.