# Tracing query execution?

**URL:** <https://discuss.elastic.co/t/tracing-query-execution/6336>\
**Category:** Elasticsearch\
**Created:** [January 10, 2012, 5:58pm UTC](https://discuss.elastic.co/t/tracing-query-execution/6336 "2012-01-10T17:58:50Z")\
**Posts on this page:** 8\
**Page:** 1

<div class="post-metadata">

**Author:** ![otisg](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/otisg/32/492_2.png) [@otisg](https://discuss.elastic.co/u/otisg)\
**Post date:** [January 10, 2012, 5:58pm UTC](https://discuss.elastic.co/t/tracing-query-execution/6336/1 "2012-01-10T17:58:50Z")

</div>

Hi,

Is there a way to "trace" query execution and see where ElasticSearch  
is spending time during query execution?  
Here is a scenario I'm seeing:

- 2-node cluster
- 1 replica
- query taking 5+ seconds
- JVM has -Xmx8g
- Server has a bunch of CPU cores
- vmstat shows hardly any disk reads and idle CPUs

Since the machine is not doing much and query latency is high, I'm  
wondering how to inspect what's going on inside ES once it receives a  
query.

Thanks,  
Otis

---

<div class="post-metadata">

**Author:** ![otisg](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/otisg/32/492_2.png) [@otisg](https://discuss.elastic.co/u/otisg)\
**Post date:** [January 10, 2012, 6:50pm UTC](https://discuss.elastic.co/t/tracing-query-execution/6336/2 "2012-01-10T18:50:34Z")

</div>

I found [Elasticsearch Platform — Find real-time answers at scale | Elastic](http://www.elasticsearch.org/guide/reference/index-modules/slowlog.html)  
and I'm wondering if this is the best tool to use?

Thanks,  
Otis

On Jan 10, 12:58 pm, Otis Gospodnetic [otis.gospodne...@gmail.com](mailto:otis.gospodne...@gmail.com)  
wrote:

> Hi,
> 
> Is there a way to "trace" query execution and see where Elasticsearch  
> is spending time during query execution?  
> Here is a scenario I'm seeing:
> 
> - 2-node cluster
> - 1 replica
> - query taking 5+ seconds
> - JVM has -Xmx8g
> - Server has a bunch of CPU cores
> - vmstat shows hardly any disk reads and idle CPUs
> 
> Since the machine is not doing much and query latency is high, I'm  
> wondering how to inspect what's going on inside ES once it receives a  
> query.
> 
> Thanks,  
> Otis

---

<div class="post-metadata">

**Author:** ![kimchy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/kimchy/32/44952_2.png) [@kimchy](https://discuss.elastic.co/u/kimchy)\
**Post date:** [January 10, 2012, 10:03pm UTC](https://discuss.elastic.co/t/tracing-query-execution/6336/3 "2012-01-10T22:03:15Z")

</div>

The slow log only logs that a query executed for a long period. What the  
query (well, search request) that you are executing?

On Tue, Jan 10, 2012 at 8:50 PM, Otis Gospodnetic \<  
[otis.gospodnetic@gmail.com](mailto:otis.gospodnetic@gmail.com)\> wrote:

> I found  
> [Elasticsearch Platform — Find real-time answers at scale | Elastic](http://www.elasticsearch.org/guide/reference/index-modules/slowlog.html)  
> and I'm wondering if this is the best tool to use?
> 
> Thanks,  
> Otis
> 
> On Jan 10, 12:58 pm, Otis Gospodnetic [otis.gospodne...@gmail.com](mailto:otis.gospodne...@gmail.com)  
> wrote:
> 
> > Hi,
> > 
> > Is there a way to "trace" query execution and see where Elasticsearch  
> > is spending time during query execution?  
> > Here is a scenario I'm seeing:
> > 
> > - 2-node cluster
> > - 1 replica
> > - query taking 5+ seconds
> > - JVM has -Xmx8g
> > - Server has a bunch of CPU cores
> > - vmstat shows hardly any disk reads and idle CPUs
> > 
> > Since the machine is not doing much and query latency is high, I'm  
> > wondering how to inspect what's going on inside ES once it receives a  
> > query.
> > 
> > Thanks,  
> > Otis

---

<div class="post-metadata">

**Author:** ![phobos182](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/phobos182/32/3011_2.png) [@phobos182](https://discuss.elastic.co/u/phobos182)\
**Post date:** [January 12, 2012, 3:24am UTC](https://discuss.elastic.co/t/tracing-query-execution/6336/4 "2012-01-12T03:24:57Z")

</div>

I ran into this as well. The SlowLog will just show you the query that is slow, and the exact JSON query. Nothing like in Solr where you can get a trace of each class, and how much time it has spent in that class.

I would love a feature request for this as it helps debugging immensely.

---

<div class="post-metadata">

**Author:** ![kimchy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/kimchy/32/44952_2.png) [@kimchy](https://discuss.elastic.co/u/kimchy)\
**Post date:** [January 12, 2012, 10:51am UTC](https://discuss.elastic.co/t/tracing-query-execution/6336/5 "2012-01-12T10:51:24Z")

</div>

How can you do that in Solr?

On Thu, Jan 12, 2012 at 5:24 AM, phobos182 [phobos182@gmail.com](mailto:phobos182@gmail.com) wrote:

> I ran into this as well. The SlowLog will just show you the query that is  
> slow, and the exact JSON query. Nothing like in Solr where you can get a  
> trace of each class, and how much time it has spent in that class.
> 
> I would love a feature request for this as it helps debugging immensely.
> 
> --  
> View this message in context:  
> [http://elasticsearch-users.115913.n3.nabble.com/Tracing-query-execution-tp3648329p3652595.html](http://elasticsearch-users.115913.n3.nabble.com/Tracing-query-execution-tp3648329p3652595.html)  
> Sent from the Elasticsearch Users mailing list archive at [Nabble.com](http://Nabble.com).

---

<div class="post-metadata">

**Author:** ![otisg](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/otisg/32/492_2.png) [@otisg](https://discuss.elastic.co/u/otisg)\
**Post date:** [January 12, 2012, 3:54pm UTC](https://discuss.elastic.co/t/tracing-query-execution/6336/6 "2012-01-12T15:54:36Z")

</div>

Yeah, what phobos182 said is what I really meant by tracing.

&debugQuery=true in Solr will show more info about where time is spent  
in Solr during query execution. Not exactly in which classes, but in  
which SearchComponents.

This can then tell if you if it's query itself that is slow or  
faceting or highlighting or some custom component you have there, etc.

Otis

On Jan 12, 5:51 am, Shay Banon [kim...@gmail.com](mailto:kim...@gmail.com) wrote:

> How can you do that in Solr?
> 
> On Thu, Jan 12, 2012 at 5:24 AM, phobos182 [phobos...@gmail.com](mailto:phobos...@gmail.com) wrote:
> 
> > I ran into this as well. The SlowLog will just show you the query that is  
> > slow, and the exact JSON query. Nothing like in Solr where you can get a  
> > trace of each class, and how much time it has spent in that class.
> 
> > I would love a feature request for this as it helps debugging immensely.
> 
> > --  
> > View this message in context:  
> > [http://elasticsearch-users.115913.n3.nabble.com/Tracing-query-executi](http://elasticsearch-users.115913.n3.nabble.com/Tracing-query-executi)...  
> > Sent from the Elasticsearch Users mailing list archive at [Nabble.com](http://Nabble.com).

---

<div class="post-metadata">

**Author:** ![kimchy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/kimchy/32/44952_2.png) [@kimchy](https://discuss.elastic.co/u/kimchy)\
**Post date:** [January 12, 2012, 6:06pm UTC](https://discuss.elastic.co/t/tracing-query-execution/6336/7 "2012-01-12T18:06:53Z")

</div>

Elasticsearch execution is a bit different. Because all is segment based  
and collector based, there are not different "stages" of search, all is  
done while the query executes.

On Thu, Jan 12, 2012 at 5:54 PM, Otis Gospodnetic \<  
[otis.gospodnetic@gmail.com](mailto:otis.gospodnetic@gmail.com)\> wrote:

> Yeah, what phobos182 said is what I really meant by tracing.
> 
> &debugQuery=true in Solr will show more info about where time is spent  
> in Solr during query execution. Not exactly in which classes, but in  
> which SearchComponents.
> 
> This can then tell if you if it's query itself that is slow or  
> faceting or highlighting or some custom component you have there, etc.
> 
> Otis
> 
> On Jan 12, 5:51 am, Shay Banon [kim...@gmail.com](mailto:kim...@gmail.com) wrote:
> 
> > How can you do that in Solr?
> > 
> > On Thu, Jan 12, 2012 at 5:24 AM, phobos182 [phobos...@gmail.com](mailto:phobos...@gmail.com) wrote:
> > 
> > > I ran into this as well. The SlowLog will just show you the query that  
> > > is  
> > > slow, and the exact JSON query. Nothing like in Solr where you can get  
> > > a  
> > > trace of each class, and how much time it has spent in that class.
> > 
> > > I would love a feature request for this as it helps debugging  
> > > immensely.
> > 
> > > --  
> > > View this message in context:  
> > > [http://elasticsearch-users.115913.n3.nabble.com/Tracing-query-executi](http://elasticsearch-users.115913.n3.nabble.com/Tracing-query-executi).  
> > > ..  
> > > Sent from the Elasticsearch Users mailing list archive at [Nabble.com](http://Nabble.com).

---

<div class="post-metadata">

**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\
**Post date:** [July 6, 2017, 3:42am UTC](https://discuss.elastic.co/t/tracing-query-execution/6336/8 "2017-07-06T03:42:55Z")

</div>


