Tracing query execution?


(Otis Gospodnetić) #1

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


(Otis Gospodnetić) #2

I found 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
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


(Shay Banon) #3

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> wrote:

I found
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
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


(phobos182) #4

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.


(Shay Banon) #5

How can you do that in Solr?

On Thu, Jan 12, 2012 at 5:24 AM, phobos182 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
Sent from the ElasticSearch Users mailing list archive at Nabble.com.


(Otis Gospodnetić) #6

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 wrote:

How can you do that in Solr?

On Thu, Jan 12, 2012 at 5:24 AM, phobos182 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...
Sent from the ElasticSearch Users mailing list archive at Nabble.com.


(Shay Banon) #7

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> 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 wrote:

How can you do that in Solr?

On Thu, Jan 12, 2012 at 5:24 AM, phobos182 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.
..

Sent from the ElasticSearch Users mailing list archive at Nabble.com.


(system) #8