Highlighting can take 50% to 99% of search time #103298
Labels
>bug
:Search Relevance/Highlighting
How a query matched a document
Team:Search Relevance
Meta label for the Search Relevance team in Elasticsearch
Comments
Testing detailsSummary of findings The customer results from running the same query with three different conditions (none of which mattered) shows that the search finished quickly, but the highlighting took ~850s. My testing results are shown in the rows below that. I ran with and without highlighting, with and without Finally I also did a second large index where the In all cases of my testing, running with highlighting causes the query to run twice as long. The other variations I tried made to no obvious difference. I captured several hot threads snapshots. The highlighting runs in the second half the query. For the first half, no highlighting activity appears in the hot threads. Below I provide 5 sample hotthreads "dumps" that I took. Hotthreads while highlighting phase is running (toggle to view) |
quux00
added
:Search/Search
quux00
changed the title
|
Pinging @elastic/es-search (Team:Search) |
elasticsearchmachine
removed
the
needs:triage
jimczi
added a commit
to jimczi/elasticsearch
that referenced
this issue
Mar 4, 2024
This change ensures that the matches implementation of the `SourceConfirmedTextQuery` only checks the current document instead of calling advance on the two phase iterator. The latter tries to find the first doc that matches the query instead of restricting the search to the current doc. This can lead to abnormally slow highlighting if the query is very restrictive and the highlight is done on a non-matching document. Closes elastic#103298
jimczi
added a commit
that referenced
this issue
Mar 5, 2024
This change ensures that the matches implementation of the `SourceConfirmedTextQuery` only checks the current document instead of calling advance on the two phase iterator. The latter tries to find the first doc that matches the query instead of restricting the search to the current doc. This can lead to abnormally slow highlighting if the query is very restrictive and the highlight is done on a non-matching document. Closes #103298
jimczi
added a commit
to jimczi/elasticsearch
that referenced
this issue
Mar 5, 2024
…5930) This change ensures that the matches implementation of the `SourceConfirmedTextQuery` only checks the current document instead of calling advance on the two phase iterator. The latter tries to find the first doc that matches the query instead of restricting the search to the current doc. This can lead to abnormally slow highlighting if the query is very restrictive and the highlight is done on a non-matching document. Closes elastic#103298
jimczi
added a commit
that referenced
this issue
Mar 6, 2024
…105983) This change ensures that the matches implementation of the `SourceConfirmedTextQuery` only checks the current document instead of calling advance on the two phase iterator. The latter tries to find the first doc that matches the query instead of restricting the search to the current doc. This can lead to abnormally slow highlighting if the query is very restrictive and the highlight is done on a non-matching document. Closes #103298
javanna
added
Team:Search Relevance
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Elasticsearch Version
8.10.4 and 8.13.0-SNAPSHOT
Installed Plugins
No response
Java Version
bundled
OS Version
ESS Cloud and MacOS
Problem Description
A customer has reported that highlighting (added by Kibana) is causing their queries in Kibana to extremely slowly. Profiling of the queries showed that 99% of the search time is spent in the Highlight code paths. In their case, the ConstantScoreQuery took less than 1 second, but the highlighting runs for ~850s (this is reproducible).
I was able to reproduce this to some degree locally (details below), where a the highlighting takes ~50% of the total search time.
Root cause is not known. Key points include:
match_only_text.Steps to Reproduce
Here is how I (partially) reproduced the issue locally.
Use the following mapping to crate an index where
messagehasmatch_only_textand 1 shard is created (I didn't test with more than 1 shard).Mapping (toggle to view)
{ "settings": { "index" : { "number_of_shards": 1, "number_of_replicas": 0 } }, "mappings": { "properties": { "@timestamp": { "type": "date" }, "message": { "type": "match_only_text" }, "kubernetes": { "properties": { "container": { "properties": { "name": { "type": "keyword", "ignore_above": 1024 } } }, "daemonset": { "properties": { "name": { "type": "keyword", "ignore_above": 1024 } } }, "deployment": { "properties": { "name": { "type": "keyword", "ignore_above": 1024 } } } } }, "bytes_sent": { "type": "long" }, "content_type": { "type": "text", "fields": { "keyword": { "type": "keyword", "ignore_above": 256 } } }, "geoip_location_lat": { "type": "float" }, "geoip_location_lon": { "type": "float" }, "is_https": { "type": "boolean" }, "request": { "type": "text", "fields": { "keyword": { "type": "keyword", "ignore_above": 256 } } }, "response": { "type": "long" }, "runtime_ms": { "type": "long" }, "url": { "type": "keyword" }, "user_Agent": { "type": "text", "fields": { "keyword": { "type": "keyword", "ignore_above": 256 } } }, "verb": { "type": "text", "fields": { "keyword": { "type": "keyword", "ignore_above": 256 } } } } } }Populate this index with at least 2.5 million records in scope for the search (see my table in comments below).
Data generation script (toggle to view)
Loading script (toggle to view)
Note I ran the above two scripts dozens of times to create data files with 100,000 to 200,000 entries, so that most of the data fell within a small-ish @timestamp range to index millions of documents.
Run the following query (has profiling and highlighting turned on).
ES Query (toggle to view)
POST sdh7687/_async_search { "profile": true, "track_total_hits": false, "sort": [ { "@timestamp": { "order": "desc", "unmapped_type": "boolean" } } ], "fields": [ { "field": "*", "include_unmapped": "true" }, { "field": "@timestamp", "format": "strict_date_optional_time" } ], "size": 10, "version": true, "script_fields": {}, "stored_fields": [ "*" ], "runtime_mappings": {}, "_source": false, "query": { "bool": { "must": [], "filter": [ { "range": { "@timestamp": { "format": "strict_date_optional_time", "gte": "2021-01-02T06:40:00.000Z", "lte": "2021-04-10T06:49:07.221Z" } } }, { "match_phrase": { "kubernetes.deployment.name": "service-integrations" } } ], "should": [], "must_not": [ { "match_phrase": { "message": "request errored" } }, { "match_phrase": { "message": "request completed" } } ] } }, "highlight": { "pre_tags": [ "@kibana-highlighted-field@" ], "post_tags": [ "@/kibana-highlighted-field@" ], "fields": { "*": {} }, "fragment_size": 2147483647 } }Logs (if relevant)
No response
The text was updated successfully, but these errors were encountered: