Search Profiler
Diagnose and debug poorly performing search queries.
This content applies to:
Elasticsearch has a powerful Profile API for debugging search queries. It provides detailed timing information about the execution of individual components in a search request. This allows users to optimize queries for better performance.
However, Profile API responses can be hard to read, especially for complex queries. Search Profiler helps you visualize these responses in a graphical interface.
Get started
Access Search Profiler under Dev Tools.
Search Profiler displays the names of the indices searched and how long it took for the query to complete.
Test it out by replacing the default match_all query with the query you want to profile, and then select Profile.
The following example shows the results of profiling the match_all query.
If you take a closer look at the information for the .security_7 sample index, the
Cumulative time field shows you that the query took 0.028ms to execute.
To see more profiling information, select View details. You'll find details about query components and the timing breakdown of low-level methods. For more information, refer to Profiling queries in the Elasticsearch documentation.
Filter for an index or type
By default, all queries executed by the Search Profiler are sent
to GET /_search.
It searches across your entire cluster (all indices, all types).
To query a specific index or type, you can use the Index filter.
In the following example, the query is executed against the indices .security-7 and kibana_sample_data_ecommerce.
This is equivalent to making a request to GET /.security-7,kibana_sample_data_ecommerce/_search.
Profile a more complicated query
To understand how the query trees are displayed inside the Search Profiler, take a look at a more complicated query.
-
Index the following data using Console:
POST test/_bulk {"index":{}} {"name":"aaron","age":23,"hair":"brown"} {"index":{}} {"name":"sue","age":19,"hair":"red"} {"index":{}} {"name":"sally","age":19,"hair":"blonde"} {"index":{}} {"name":"george","age":19,"hair":"blonde"} {"index":{}} {"name":"fred","age":69,"hair":"blonde"} -
From the Search Profiler, enter test in the Index field to restrict profiled queries to the
testindex. -
Replace the default
match_allquery in the query editor with a query that has two sub-query components and includes a simple aggregation:{ "query": { "bool": { "should": [ { "match": { "name": "fred" } }, { "terms": { "name": [ "sue", "sally" ] } } ] } }, "aggs": { "stats": { "stats": { "field": "price" } } } } -
Select Profile to profile the query and visualize the results.
- The top
BooleanQuerycomponent corresponds to theboolin the query. - The second
BooleanQuerycorresponds to thetermsquery, which is internally converted to aBooleanofshouldclauses. It has two child queries that correspond to "sally" and "sue from thetermsquery. - The
TermQuerythat's labeled with "name:fred" corresponds tomatch: fredin the query.
In the time columns, the Self time and Total time are no longer identical on all rows:
- Self time represents how long the query component took to execute.
- Total time is the time a query component and all its children took to execute.
Therefore, queries like the Boolean queries often have a larger total time than self time.
- The top
-
Select Aggregation Profile to view aggregation profiling statistics.
This query includes a
statsagg on the"age"field. The Aggregation Profile tab is only enabled when the query being profiled contains an aggregation. -
Select View details to view the timing breakdown.
For more information about how the Search Profiler works, how timings are calculated, and how to interpret various results, refer to Profiling queries in the Elasticsearch documentation.
Render pre-captured profiler JSON
Sometimes you might want to investigate performance problems that are temporal in nature. For example, a query might only be slow at certain time of day when many customers are using your system. You can set up a process to automatically profile slow queries when they occur and then save those profile responses for later analysis.
The Search Profiler supports this workflow by allowing you to paste the pre-captured JSON in the query editor. The Search Profiler will detect that you have entered a JSON response (rather than a query) and will render just the visualization, rather than querying the cluster.
To see how this works, copy and paste the following profile response into the query editor and select Profile.
{
"took": 3,
"timed_out": false,
"_shards": {
"total": 1,
"successful": 1,
"failed": 0
},
"hits": {
"total": 1,
"max_score": 1.3862944,
"hits": [
{
"_index": "test",
"_type": "test",
"_id": "AVi3aRDmGKWpaS38wV57",
"_score": 1.3862944,
"_source": {
"name": "fred",
"age": 69,
"hair": "blonde"
}
}
]
},
"profile": {
"shards": [
{
"id": "[O-l25nM4QN6Z68UA5rUYqQ][test][0]",
"searches": [
{
"query": [
{
"type": "BooleanQuery",
"description": "+name:fred #(ConstantScore(*:*))^0.0",
"time": "0.5884370000ms",
"breakdown": {
"score": 7243,
"build_scorer_count": 1,
"match_count": 0,
"create_weight": 196239,
"next_doc": 9851,
"match": 0,
"create_weight_count": 1,
"next_doc_count": 2,
"score_count": 1,
"build_scorer": 375099,
"advance": 0,
"advance_count": 0
},
"children": [
{
"type": "TermQuery",
"description": "name:fred",
"time": "0.3016880000ms",
"breakdown": {
"score": 4218,
"build_scorer_count": 1,
"match_count": 0,
"create_weight": 132425,
"next_doc": 2196,
"match": 0,
"create_weight_count": 1,
"next_doc_count": 2,
"score_count": 1,
"build_scorer": 162844,
"advance": 0,
"advance_count": 0
}
},
{
"type": "BoostQuery",
"description": "(ConstantScore(*:*))^0.0",
"time": "0.1223030000ms",
"breakdown": {
"score": 0,
"build_scorer_count": 1,
"match_count": 0,
"create_weight": 17366,
"next_doc": 0,
"match": 0,
"create_weight_count": 1,
"next_doc_count": 0,
"score_count": 0,
"build_scorer": 102329,
"advance": 2604,
"advance_count": 2
},
"children": [
{
"type": "MatchAllDocsQuery",
"description": "*:*",
"time": "0.03307600000ms",
"breakdown": {
"score": 0,
"build_scorer_count": 1,
"match_count": 0,
"create_weight": 6068,
"next_doc": 0,
"match": 0,
"create_weight_count": 1,
"next_doc_count": 0,
"score_count": 0,
"build_scorer": 25615,
"advance": 1389,
"advance_count": 2
}
}
]
}
]
}
],
"rewrite_time": 168640,
"collector": [
{
"name": "CancellableCollector",
"reason": "search_cancelled",
"time": "0.02952900000ms",
"children": [
{
"name": "SimpleTopScoreDocCollector",
"reason": "search_top_hits",
"time": "0.01931700000ms"
}
]
}
]
}
],
"aggregations": []
}
]
}
}Your output should look similar to this: