Measuring timing with debugQuery=true

[Rahul R <ra...@gmail.com>]

Hello,
I am trying to measure why some of my queries take a long time. I am using
EmbeddedSolrServer and with logging statements before and
after the EmbeddedSolrServer.query(SolrQuery) function, I have found the
time to be around 16s. I added the debugQuery=true and the timing component
for this reads as following:

*
timing:{time=2438.0,prepare={time=0.0,org.apache.solr.handler.component.QueryComponent={time=0.0},org.apache.solr.handler.component.FacetComponent={time=0.0},org.apache.solr.handler.component.MoreLikeThisComponent={time=0.0},org.apache.solr.handler.component.HighlightComponent={time=0.0},org.apache.solr.handler.component.DebugComponent={time=0.0}},process={time=2438.0,org.apache.solr.handler.component.QueryComponent={time=2438.0},org.apache.solr.handler.component.FacetComponent={time=0.0},org.apache.solr.handler.component.MoreLikeThisComponent={time=0.0},org.apache.solr.handler.component.HighlightComponent={time=0.0},org.apache.solr.handler.component.DebugComponent={time=0.0}}}
*

As you can see, this shows only 2.4s being used by the query. I can't seem
to figure out where the rest of the time is being spent. This is within my
office intranet and I don't think the request-response time over the wire
will cause significant overhead. So my question : is the timing information
presented here comprehensive or are there more time consuming operations
that are not represented here ? I guess GC pause times could be one answer
(I hope not !).... Also, the above result was for a faceted query. I can't
understand why the FacetComponent would be zero. Any thoughts ?

Rahul

Re: Measuring timing with debugQuery=true

[Yonik Seeley <yo...@lucidimagination.com>]

It's harder debugging stuff like this with custom code (you say that
you're using EmbeddedSolrServer) and different servlet containers.

Perahps try putting your config files and index into the example jetty
server, and then do a single request from curl or your web browser to
see if the times are still long.

-Yonik
http://www.lucidimagination.com



On Tue, Sep 29, 2009 at 9:42 AM, Rahul R <ra...@gmail.com> wrote:
> Sorry for the delayed response
>
> How big are your documents?
> I have totally 1 million documents. I have totally 1950 fields in the index.
> Every document would probably have values for around 20 - 50 fields.
> What is the total size of the index?
> 1 GB
> What's the amout of RAM on your box? How big is the JVM heap (and how much
> free memory is left on your system)?
> I have 4 GB RAM. I am using Weblogic 10, 32 Bit. Since it is a windows box,
> I am able to allocate only 1 GB to the JVM. No other applications are
> running on the system. So the entire 4GB is at the disposal of the
> application. I am simulating load using a load tool (15 users)
> Can you show what this slow query looks like (the whole request)?
> q=*%3A*&rows=0&facet=true&facet.mincount=1&facet.limit=2&f.S9942.facet.limit=100&facet.field=S9942&facet.field=S6878&facet.field=S9156&facet.field=S0369&facet.field=S9926&facet.field=S1421&facet.field=S8990&facet.field=S6881&facet.field=S3552&debugQuery=true
> q=*%3A*&fq=S9942%3A%22TEXAS+INSTRUMENTS%22&rows=0&facet=true&facet.mincount=1&facet.limit=2&facet.field=S9942&facet.field=S6878&facet.field=S9156&facet.field=S0369&facet.field=S9926&facet.field=S1421&facet.field=S8990&facet.field=S6881&facet.field=S3552&debugQuery=true
>
> Other information
> Solr 1.3, JDK 1.5.0_14
>
> regards
> Rahul
>
> On Mon, Sep 28, 2009 at 6:48 PM, Yonik Seeley <yo...@lucidimagination.com>
> wrote:
>>
>> On Mon, Sep 28, 2009 at 7:51 AM, Rahul R <ra...@gmail.com> wrote:
>> > Yonik,
>> > I understand that the network can be a bottle-neck but I am pretty sure
>> > that
>> > it is not. I am operating on a 100 MBPS intranet....... How do I ensure
>> > that
>> > stored fields are cached by the OS ? Only the Solr caches within the JVM
>> > are
>> > under my control...... The result set has around 10K documents of which
>> > I am
>> > retrieving only 10......I am displaying a max of only 3 fields per
>> > document
>> > in my result set. Can the reading time for these stored fields be so
>> > long ?
>>
>> It could be a seek per document if the index is too big to fit in the
>> OS cache - but that still wouldn't be as slow as you report.
>> Something is fishy here.
>>
>> How big are your documents?
>> What is the total size of the index?
>> What's the amout of RAM on your box?
>> How big is the JVM heap (and how much free memory is left on your system)?
>> Can you show what this slow query looks like (the whole request)?
>>
>> > I have totally around 1 million documents in my index........ Any
>> > thoughts
>> > on why the FacetComponent does not take any time while the
>> > QueryComponent
>> > takes around 2.4s.
>>
>> It could be a field that has very few unique values and faceting just
>> completes quickly.
>> Make sure you're actually getting faceting data back (that it's
>> correctly turned on).
>>
>> -Yonik
>> http://www.lucidimagination.com
>>
>> > I am doing a faceted and keyword query ie I have both 'q'
>> > and 'fq' params in my query.... Thank you for your response.
>> >
>> > Regards
>> > Rahul
>> >
>> > On Mon, Sep 28, 2009 at 1:20 AM, Yonik Seeley
>> > <yo...@lucidimagination.com>
>> > wrote:
>> >>
>> >> The response times in a Solr request don't include the time to read
>> >> stored fields (since the response is streamed) and doesn't include the
>> >> time to transfer/read the response (which can be increased by a
>> >> slow/congested network link, or a slow client that doesn't read the
>> >> response immediately).
>> >>
>> >> How many documents are you retrieving?  Reading stored fields for
>> >> documents can be slow if they aren't cached by the OS since it's often
>> >> a disk seek per document read for a large index.
>> >>
>> >> -Yonik
>> >> http://www.lucidimagination.com
>> >>
>> >>
>> >>
>> >> On Sun, Sep 27, 2009 at 3:41 PM, Rahul R <ra...@gmail.com> wrote:
>> >> > Hello,
>> >> > I am trying to measure why some of my queries take a long time. I am
>> >> > using
>> >> > EmbeddedSolrServer and with logging statements before and
>> >> > after the EmbeddedSolrServer.query(SolrQuery) function, I have found
>> >> > the
>> >> > time to be around 16s. I added the debugQuery=true and the timing
>> >> > component
>> >> > for this reads as following:
>> >> >
>> >> > *
>> >> >
>> >> >
>> >> > timing:{time=2438.0,prepare={time=0.0,org.apache.solr.handler.component.QueryComponent={time=0.0},org.apache.solr.handler.component.FacetComponent={time=0.0},org.apache.solr.handler.component.MoreLikeThisComponent={time=0.0},org.apache.solr.handler.component.HighlightComponent={time=0.0},org.apache.solr.handler.component.DebugComponent={time=0.0}},process={time=2438.0,org.apache.solr.handler.component.QueryComponent={time=2438.0},org.apache.solr.handler.component.FacetComponent={time=0.0},org.apache.solr.handler.component.MoreLikeThisComponent={time=0.0},org.apache.solr.handler.component.HighlightComponent={time=0.0},org.apache.solr.handler.component.DebugComponent={time=0.0}}}
>> >> > *
>> >> >
>> >> > As you can see, this shows only 2.4s being used by the query. I can't
>> >> > seem
>> >> > to figure out where the rest of the time is being spent. This is
>> >> > within
>> >> > my
>> >> > office intranet and I don't think the request-response time over the
>> >> > wire
>> >> > will cause significant overhead. So my question : is the timing
>> >> > information
>> >> > presented here comprehensive or are there more time consuming
>> >> > operations
>> >> > that are not represented here ? I guess GC pause times could be one
>> >> > answer
>> >> > (I hope not !).... Also, the above result was for a faceted query. I
>> >> > can't
>> >> > understand why the FacetComponent would be zero. Any thoughts ?
>> >> >
>> >> > Rahul
>> >> >
>> >
>> >
>
>

Re: Measuring timing with debugQuery=true

[Rahul R <ra...@gmail.com>]

I just want to clarify here that I understand my memory allocation might be
less given the load on the system. The response times were only slightly
better when we ran the test on a Solaris box with 12CPU, 24G RAM and with
3.2 GB allocated for the JVM..... I know that I have a performance
problem. My main concern is to identify the reasons for the inconsistency
between the timing information shown between the debugQuery output (2.4s)
and the entire time taken by the EmbeddedSolrServer.query(SolrQuery)
function (16s). I feel that if I can find out where the remaining 13.6s gets
used, then I can look to improve accordingly. Thank you.

Regards
Rahul

On Tue, Sep 29, 2009 at 7:12 PM, Rahul R <ra...@gmail.com> wrote:

> Sorry for the delayed response
>  **
> *How big are your documents?*
> I have totally 1 million documents. I have totally 1950 fields in the
> index. Every document would probably have values for around 20 - 50 fields.
>  *What is the total size of the index?*
> 1 GB
>
> *What's the amout of RAM on your box? How big is the JVM heap (and how
> much free memory is left on your system)?*
> I have 4 GB RAM. I am using Weblogic 10, 32 Bit. Since it is a windows box,
> I am able to allocate only 1 GB to the JVM. No other applications are
> running on the system. So the entire 4GB is at the disposal of the
> application. I am simulating load using a load tool (15 users)
>
> *Can you show what this slow query looks like (the whole request)?*
>
> q=*%3A*&rows=0&facet=true&facet.mincount=1&facet.limit=2&f.S9942.facet.limit=100&facet.field=S9942&facet.field=S6878&facet.field=S9156&facet.field=S0369&facet.field=S9926&facet.field=S1421&facet.field=S8990&facet.field=S6881&facet.field=S3552&debugQuery=true
>
>
> q=*%3A*&fq=S9942%3A%22TEXAS+INSTRUMENTS%22&rows=0&facet=true&facet.mincount=1&facet.limit=2&facet.field=S9942&facet.field=S6878&facet.field=S9156&facet.field=S0369&facet.field=S9926&facet.field=S1421&facet.field=S8990&facet.field=S6881&facet.field=S3552&debugQuery=true
>
> Other information
> Solr 1.3, JDK 1.5.0_14
>
> regards
> Rahul
>
>   On Mon, Sep 28, 2009 at 6:48 PM, Yonik Seeley <
> yonik@lucidimagination.com> wrote:
>
>> On Mon, Sep 28, 2009 at 7:51 AM, Rahul R <ra...@gmail.com> wrote:
>> > Yonik,
>> > I understand that the network can be a bottle-neck but I am pretty sure
>> that
>> > it is not. I am operating on a 100 MBPS intranet....... How do I ensure
>> that
>> > stored fields are cached by the OS ? Only the Solr caches within the JVM
>> are
>> > under my control...... The result set has around 10K documents of which
>> I am
>> > retrieving only 10......I am displaying a max of only 3 fields per
>> document
>> > in my result set. Can the reading time for these stored fields be so
>> long ?
>>
>> It could be a seek per document if the index is too big to fit in the
>> OS cache - but that still wouldn't be as slow as you report.
>> Something is fishy here.
>>
>> How big are your documents?
>> What is the total size of the index?
>> What's the amout of RAM on your box?
>> How big is the JVM heap (and how much free memory is left on your system)?
>> Can you show what this slow query looks like (the whole request)?
>>
>> > I have totally around 1 million documents in my index........ Any
>> thoughts
>> > on why the FacetComponent does not take any time while the
>> QueryComponent
>> > takes around 2.4s.
>>
>> It could be a field that has very few unique values and faceting just
>> completes quickly.
>> Make sure you're actually getting faceting data back (that it's
>> correctly turned on).
>>
>> -Yonik
>> http://www.lucidimagination.com
>>
>> > I am doing a faceted and keyword query ie I have both 'q'
>> > and 'fq' params in my query.... Thank you for your response.
>> >
>> > Regards
>> > Rahul
>> >
>> > On Mon, Sep 28, 2009 at 1:20 AM, Yonik Seeley <
>> yonik@lucidimagination.com>
>> > wrote:
>> >>
>> >> The response times in a Solr request don't include the time to read
>> >> stored fields (since the response is streamed) and doesn't include the
>> >> time to transfer/read the response (which can be increased by a
>> >> slow/congested network link, or a slow client that doesn't read the
>> >> response immediately).
>> >>
>> >> How many documents are you retrieving?  Reading stored fields for
>> >> documents can be slow if they aren't cached by the OS since it's often
>> >> a disk seek per document read for a large index.
>> >>
>> >> -Yonik
>> >> http://www.lucidimagination.com
>> >>
>> >>
>> >>
>> >> On Sun, Sep 27, 2009 at 3:41 PM, Rahul R <ra...@gmail.com> wrote:
>> >> > Hello,
>> >> > I am trying to measure why some of my queries take a long time. I am
>> >> > using
>> >> > EmbeddedSolrServer and with logging statements before and
>> >> > after the EmbeddedSolrServer.query(SolrQuery) function, I have found
>> the
>> >> > time to be around 16s. I added the debugQuery=true and the timing
>> >> > component
>> >> > for this reads as following:
>> >> >
>> >> > *
>> >> >
>> >> >
>> timing:{time=2438.0,prepare={time=0.0,org.apache.solr.handler.component.QueryComponent={time=0.0},org.apache.solr.handler.component.FacetComponent={time=0.0},org.apache.solr.handler.component.MoreLikeThisComponent={time=0.0},org.apache.solr.handler.component.HighlightComponent={time=0.0},org.apache.solr.handler.component.DebugComponent={time=0.0}},process={time=2438.0,org.apache.solr.handler.component.QueryComponent={time=2438.0},org.apache.solr.handler.component.FacetComponent={time=0.0},org.apache.solr.handler.component.MoreLikeThisComponent={time=0.0},org.apache.solr.handler.component.HighlightComponent={time=0.0},org.apache.solr.handler.component.DebugComponent={time=0.0}}}
>> >> > *
>> >> >
>> >> > As you can see, this shows only 2.4s being used by the query. I can't
>> >> > seem
>> >> > to figure out where the rest of the time is being spent. This is
>> within
>> >> > my
>> >> > office intranet and I don't think the request-response time over the
>> >> > wire
>> >> > will cause significant overhead. So my question : is the timing
>> >> > information
>> >> > presented here comprehensive or are there more time consuming
>> operations
>> >> > that are not represented here ? I guess GC pause times could be one
>> >> > answer
>> >> > (I hope not !).... Also, the above result was for a faceted query. I
>> >> > can't
>> >> > understand why the FacetComponent would be zero. Any thoughts ?
>> >> >
>> >> > Rahul
>> >> >
>> >
>> >
>>
>
>

Re: Measuring timing with debugQuery=true

[Rahul R <ra...@gmail.com>]

Sorry for the delayed response
**
*How big are your documents?*
I have totally 1 million documents. I have totally 1950 fields in the index.
Every document would probably have values for around 20 - 50 fields.
*What is the total size of the index?*
1 GB

*What's the amout of RAM on your box? How big is the JVM heap (and how much
free memory is left on your system)?*
I have 4 GB RAM. I am using Weblogic 10, 32 Bit. Since it is a windows box,
I am able to allocate only 1 GB to the JVM. No other applications are
running on the system. So the entire 4GB is at the disposal of the
application. I am simulating load using a load tool (15 users)

*Can you show what this slow query looks like (the whole request)?*
q=*%3A*&rows=0&facet=true&facet.mincount=1&facet.limit=2&f.S9942.facet.limit=100&facet.field=S9942&facet.field=S6878&facet.field=S9156&facet.field=S0369&facet.field=S9926&facet.field=S1421&facet.field=S8990&facet.field=S6881&facet.field=S3552&debugQuery=true

q=*%3A*&fq=S9942%3A%22TEXAS+INSTRUMENTS%22&rows=0&facet=true&facet.mincount=1&facet.limit=2&facet.field=S9942&facet.field=S6878&facet.field=S9156&facet.field=S0369&facet.field=S9926&facet.field=S1421&facet.field=S8990&facet.field=S6881&facet.field=S3552&debugQuery=true

Other information
Solr 1.3, JDK 1.5.0_14

regards
Rahul

On Mon, Sep 28, 2009 at 6:48 PM, Yonik Seeley <yo...@lucidimagination.com>wrote:

> On Mon, Sep 28, 2009 at 7:51 AM, Rahul R <ra...@gmail.com> wrote:
> > Yonik,
> > I understand that the network can be a bottle-neck but I am pretty sure
> that
> > it is not. I am operating on a 100 MBPS intranet....... How do I ensure
> that
> > stored fields are cached by the OS ? Only the Solr caches within the JVM
> are
> > under my control...... The result set has around 10K documents of which I
> am
> > retrieving only 10......I am displaying a max of only 3 fields per
> document
> > in my result set. Can the reading time for these stored fields be so long
> ?
>
> It could be a seek per document if the index is too big to fit in the
> OS cache - but that still wouldn't be as slow as you report.
> Something is fishy here.
>
> How big are your documents?
> What is the total size of the index?
> What's the amout of RAM on your box?
> How big is the JVM heap (and how much free memory is left on your system)?
> Can you show what this slow query looks like (the whole request)?
>
> > I have totally around 1 million documents in my index........ Any
> thoughts
> > on why the FacetComponent does not take any time while the QueryComponent
> > takes around 2.4s.
>
> It could be a field that has very few unique values and faceting just
> completes quickly.
> Make sure you're actually getting faceting data back (that it's
> correctly turned on).
>
> -Yonik
> http://www.lucidimagination.com
>
> > I am doing a faceted and keyword query ie I have both 'q'
> > and 'fq' params in my query.... Thank you for your response.
> >
> > Regards
> > Rahul
> >
> > On Mon, Sep 28, 2009 at 1:20 AM, Yonik Seeley <
> yonik@lucidimagination.com>
> > wrote:
> >>
> >> The response times in a Solr request don't include the time to read
> >> stored fields (since the response is streamed) and doesn't include the
> >> time to transfer/read the response (which can be increased by a
> >> slow/congested network link, or a slow client that doesn't read the
> >> response immediately).
> >>
> >> How many documents are you retrieving?  Reading stored fields for
> >> documents can be slow if they aren't cached by the OS since it's often
> >> a disk seek per document read for a large index.
> >>
> >> -Yonik
> >> http://www.lucidimagination.com
> >>
> >>
> >>
> >> On Sun, Sep 27, 2009 at 3:41 PM, Rahul R <ra...@gmail.com> wrote:
> >> > Hello,
> >> > I am trying to measure why some of my queries take a long time. I am
> >> > using
> >> > EmbeddedSolrServer and with logging statements before and
> >> > after the EmbeddedSolrServer.query(SolrQuery) function, I have found
> the
> >> > time to be around 16s. I added the debugQuery=true and the timing
> >> > component
> >> > for this reads as following:
> >> >
> >> > *
> >> >
> >> >
> timing:{time=2438.0,prepare={time=0.0,org.apache.solr.handler.component.QueryComponent={time=0.0},org.apache.solr.handler.component.FacetComponent={time=0.0},org.apache.solr.handler.component.MoreLikeThisComponent={time=0.0},org.apache.solr.handler.component.HighlightComponent={time=0.0},org.apache.solr.handler.component.DebugComponent={time=0.0}},process={time=2438.0,org.apache.solr.handler.component.QueryComponent={time=2438.0},org.apache.solr.handler.component.FacetComponent={time=0.0},org.apache.solr.handler.component.MoreLikeThisComponent={time=0.0},org.apache.solr.handler.component.HighlightComponent={time=0.0},org.apache.solr.handler.component.DebugComponent={time=0.0}}}
> >> > *
> >> >
> >> > As you can see, this shows only 2.4s being used by the query. I can't
> >> > seem
> >> > to figure out where the rest of the time is being spent. This is
> within
> >> > my
> >> > office intranet and I don't think the request-response time over the
> >> > wire
> >> > will cause significant overhead. So my question : is the timing
> >> > information
> >> > presented here comprehensive or are there more time consuming
> operations
> >> > that are not represented here ? I guess GC pause times could be one
> >> > answer
> >> > (I hope not !).... Also, the above result was for a faceted query. I
> >> > can't
> >> > understand why the FacetComponent would be zero. Any thoughts ?
> >> >
> >> > Rahul
> >> >
> >
> >
>

Re: Measuring timing with debugQuery=true

[Yonik Seeley <yo...@lucidimagination.com>]

On Mon, Sep 28, 2009 at 7:51 AM, Rahul R <ra...@gmail.com> wrote:
> Yonik,
> I understand that the network can be a bottle-neck but I am pretty sure that
> it is not. I am operating on a 100 MBPS intranet....... How do I ensure that
> stored fields are cached by the OS ? Only the Solr caches within the JVM are
> under my control...... The result set has around 10K documents of which I am
> retrieving only 10......I am displaying a max of only 3 fields per document
> in my result set. Can the reading time for these stored fields be so long ?

It could be a seek per document if the index is too big to fit in the
OS cache - but that still wouldn't be as slow as you report.
Something is fishy here.

How big are your documents?
What is the total size of the index?
What's the amout of RAM on your box?
How big is the JVM heap (and how much free memory is left on your system)?
Can you show what this slow query looks like (the whole request)?

> I have totally around 1 million documents in my index........ Any thoughts
> on why the FacetComponent does not take any time while the QueryComponent
> takes around 2.4s.

It could be a field that has very few unique values and faceting just
completes quickly.
Make sure you're actually getting faceting data back (that it's
correctly turned on).

-Yonik
http://www.lucidimagination.com

> I am doing a faceted and keyword query ie I have both 'q'
> and 'fq' params in my query.... Thank you for your response.
>
> Regards
> Rahul
>
> On Mon, Sep 28, 2009 at 1:20 AM, Yonik Seeley <yo...@lucidimagination.com>
> wrote:
>>
>> The response times in a Solr request don't include the time to read
>> stored fields (since the response is streamed) and doesn't include the
>> time to transfer/read the response (which can be increased by a
>> slow/congested network link, or a slow client that doesn't read the
>> response immediately).
>>
>> How many documents are you retrieving?  Reading stored fields for
>> documents can be slow if they aren't cached by the OS since it's often
>> a disk seek per document read for a large index.
>>
>> -Yonik
>> http://www.lucidimagination.com
>>
>>
>>
>> On Sun, Sep 27, 2009 at 3:41 PM, Rahul R <ra...@gmail.com> wrote:
>> > Hello,
>> > I am trying to measure why some of my queries take a long time. I am
>> > using
>> > EmbeddedSolrServer and with logging statements before and
>> > after the EmbeddedSolrServer.query(SolrQuery) function, I have found the
>> > time to be around 16s. I added the debugQuery=true and the timing
>> > component
>> > for this reads as following:
>> >
>> > *
>> >
>> > timing:{time=2438.0,prepare={time=0.0,org.apache.solr.handler.component.QueryComponent={time=0.0},org.apache.solr.handler.component.FacetComponent={time=0.0},org.apache.solr.handler.component.MoreLikeThisComponent={time=0.0},org.apache.solr.handler.component.HighlightComponent={time=0.0},org.apache.solr.handler.component.DebugComponent={time=0.0}},process={time=2438.0,org.apache.solr.handler.component.QueryComponent={time=2438.0},org.apache.solr.handler.component.FacetComponent={time=0.0},org.apache.solr.handler.component.MoreLikeThisComponent={time=0.0},org.apache.solr.handler.component.HighlightComponent={time=0.0},org.apache.solr.handler.component.DebugComponent={time=0.0}}}
>> > *
>> >
>> > As you can see, this shows only 2.4s being used by the query. I can't
>> > seem
>> > to figure out where the rest of the time is being spent. This is within
>> > my
>> > office intranet and I don't think the request-response time over the
>> > wire
>> > will cause significant overhead. So my question : is the timing
>> > information
>> > presented here comprehensive or are there more time consuming operations
>> > that are not represented here ? I guess GC pause times could be one
>> > answer
>> > (I hope not !).... Also, the above result was for a faceted query. I
>> > can't
>> > understand why the FacetComponent would be zero. Any thoughts ?
>> >
>> > Rahul
>> >
>
>

Re: Measuring timing with debugQuery=true

[Rahul R <ra...@gmail.com>]

Yonik,
I understand that the network can be a bottle-neck but I am pretty sure that
it is not. I am operating on a 100 MBPS intranet....... How do I ensure that
stored fields are cached by the OS ? Only the Solr caches within the JVM are
under my control...... The result set has around 10K documents of which I am
retrieving only 10......I am displaying a max of only 3 fields per document
in my result set. Can the reading time for these stored fields be so long ?
I have totally around 1 million documents in my index........ Any thoughts
on why the FacetComponent does not take any time while the QueryComponent
takes around 2.4s. I am doing a faceted and keyword query ie I have both 'q'
and 'fq' params in my query.... Thank you for your response.

Regards
Rahul

On Mon, Sep 28, 2009 at 1:20 AM, Yonik Seeley <yo...@lucidimagination.com>wrote:

> The response times in a Solr request don't include the time to read
> stored fields (since the response is streamed) and doesn't include the
> time to transfer/read the response (which can be increased by a
> slow/congested network link, or a slow client that doesn't read the
> response immediately).
>
> How many documents are you retrieving?  Reading stored fields for
> documents can be slow if they aren't cached by the OS since it's often
> a disk seek per document read for a large index.
>
> -Yonik
> http://www.lucidimagination.com
>
>
>
> On Sun, Sep 27, 2009 at 3:41 PM, Rahul R <ra...@gmail.com> wrote:
> > Hello,
> > I am trying to measure why some of my queries take a long time. I am
> using
> > EmbeddedSolrServer and with logging statements before and
> > after the EmbeddedSolrServer.query(SolrQuery) function, I have found the
> > time to be around 16s. I added the debugQuery=true and the timing
> component
> > for this reads as following:
> >
> > *
> >
> timing:{time=2438.0,prepare={time=0.0,org.apache.solr.handler.component.QueryComponent={time=0.0},org.apache.solr.handler.component.FacetComponent={time=0.0},org.apache.solr.handler.component.MoreLikeThisComponent={time=0.0},org.apache.solr.handler.component.HighlightComponent={time=0.0},org.apache.solr.handler.component.DebugComponent={time=0.0}},process={time=2438.0,org.apache.solr.handler.component.QueryComponent={time=2438.0},org.apache.solr.handler.component.FacetComponent={time=0.0},org.apache.solr.handler.component.MoreLikeThisComponent={time=0.0},org.apache.solr.handler.component.HighlightComponent={time=0.0},org.apache.solr.handler.component.DebugComponent={time=0.0}}}
> > *
> >
> > As you can see, this shows only 2.4s being used by the query. I can't
> seem
> > to figure out where the rest of the time is being spent. This is within
> my
> > office intranet and I don't think the request-response time over the wire
> > will cause significant overhead. So my question : is the timing
> information
> > presented here comprehensive or are there more time consuming operations
> > that are not represented here ? I guess GC pause times could be one
> answer
> > (I hope not !).... Also, the above result was for a faceted query. I
> can't
> > understand why the FacetComponent would be zero. Any thoughts ?
> >
> > Rahul
> >
>

Re: Measuring timing with debugQuery=true

[Yonik Seeley <yo...@lucidimagination.com>]

The response times in a Solr request don't include the time to read
stored fields (since the response is streamed) and doesn't include the
time to transfer/read the response (which can be increased by a
slow/congested network link, or a slow client that doesn't read the
response immediately).

How many documents are you retrieving?  Reading stored fields for
documents can be slow if they aren't cached by the OS since it's often
a disk seek per document read for a large index.

-Yonik
http://www.lucidimagination.com



On Sun, Sep 27, 2009 at 3:41 PM, Rahul R <ra...@gmail.com> wrote:
> Hello,
> I am trying to measure why some of my queries take a long time. I am using
> EmbeddedSolrServer and with logging statements before and
> after the EmbeddedSolrServer.query(SolrQuery) function, I have found the
> time to be around 16s. I added the debugQuery=true and the timing component
> for this reads as following:
>
> *
> timing:{time=2438.0,prepare={time=0.0,org.apache.solr.handler.component.QueryComponent={time=0.0},org.apache.solr.handler.component.FacetComponent={time=0.0},org.apache.solr.handler.component.MoreLikeThisComponent={time=0.0},org.apache.solr.handler.component.HighlightComponent={time=0.0},org.apache.solr.handler.component.DebugComponent={time=0.0}},process={time=2438.0,org.apache.solr.handler.component.QueryComponent={time=2438.0},org.apache.solr.handler.component.FacetComponent={time=0.0},org.apache.solr.handler.component.MoreLikeThisComponent={time=0.0},org.apache.solr.handler.component.HighlightComponent={time=0.0},org.apache.solr.handler.component.DebugComponent={time=0.0}}}
> *
>
> As you can see, this shows only 2.4s being used by the query. I can't seem
> to figure out where the rest of the time is being spent. This is within my
> office intranet and I don't think the request-response time over the wire
> will cause significant overhead. So my question : is the timing information
> presented here comprehensive or are there more time consuming operations
> that are not represented here ? I guess GC pause times could be one answer
> (I hope not !).... Also, the above result was for a faceted query. I can't
> understand why the FacetComponent would be zero. Any thoughts ?
>
> Rahul
>