Re: Random Slowness
Or simply attach to the JVM with Jconsole and watch the GC from there. You'd have to watch things (logs and jconsole) closely though, and correlate the slow query periods with a GC spike. Otis -- Sematext -- http://sematext.com/ -- Lucene - Solr - Nutch - Original Message > From: Ed Summers > To: solr-user@lucene.apache.org > Sent: Wednesday, July 22, 2009 11:03:08 AM > Subject: Re: Random Slowness > > On Wed, Jul 22, 2009 at 10:44 AM, Jeff Newburnwrote: > > How do I go about enabling the gc logging for solr? > > It depends how you are running solr. You basically want to make sure > that when the JVM is started up with the java command, that it gets > some additional arguments [1]. So for example if you are running solr > using jetty you would: > > java -verbose:gc -Xloggc:solr_gc.log -jar start.jar > > And then poke around in the log looking for garbage collection events > that take as long as the pauses you are seeing in your app. I think > there are tools that will help you analyze the log files if you need > them. If there is a correlation you'll probably want to tune your solr > memory usage with -xMx and -xMs. > > Hope this helps. > > //Ed > > [1] http://java.sun.com/javase/7/docs/technotes/tools/windows/java.html
Re: Random Slowness
On Wed, Jul 22, 2009 at 10:44 AM, Jeff Newburn wrote: > How do I go about enabling the gc logging for solr? It depends how you are running solr. You basically want to make sure that when the JVM is started up with the java command, that it gets some additional arguments [1]. So for example if you are running solr using jetty you would: java -verbose:gc -Xloggc:solr_gc.log -jar start.jar And then poke around in the log looking for garbage collection events that take as long as the pauses you are seeing in your app. I think there are tools that will help you analyze the log files if you need them. If there is a correlation you'll probably want to tune your solr memory usage with -xMx and -xMs. Hope this helps. //Ed [1] http://java.sun.com/javase/7/docs/technotes/tools/windows/java.html
Re: Random Slowness
Ed,
How do I go about enabling the gc logging for solr?
--
Jeff Newburn
Software Engineer, Zappos.com
jnewb...@zappos.com - 702-943-7562
> From: Ed Summers
> Reply-To:
> Date: Wed, 22 Jul 2009 10:39:03 -0400
> To:
> Subject: Re: Random Slowness
>
> I haven't read this whole thread, so maybe it's already come up. Have
> you turned on the garbage collection logging to see if the jvm is busy
> cleaning up when you are seeing the slowness? Maybe the jvm is
> struggling to keep the heap size within a particular limit?
>
> //Ed
>
> On Wed, Jul 22, 2009 at 10:22 AM, Jeff Newburn wrote:
>> We can never reproduce the slowness with the same query. As soon as we try
>> to run them again they are fine. I have even tried running the same query
>> the next day and it is fine.
>>
>> All of our requests go through our dismax handler which is part of why it is
>> so weird. Most queries are fine, however just occasionally they aren't.
>> Additionally, why would the command=details command also go slow? That
>> seems like a server issue.
>>
>> It appears that for FieldValueCache and FilterCache we have no evictions,
>> but for queryResultCache and DocumentCache there are a good number of
>> evictions. How would I help lower the evictions to see if that is the
>> problem?
>>
>> Dismax Config below:
>> > default="true">
>> ?
>>
>> explicit
>> 0.5
>> ?
>>
>>
>> productId^10.0
>>
>> personality^8.0
>> subCategory^8.0
>> category^6.0
>> productType^5.0
>>
>> brandName^1.0
>> realBrandName^1.0
>> productNameSearch^1.0
>>
>> size^1.2
>> width^1.0
>> heelHeight^1.0
>>
>> productDescription^1.0
>> color^10.0
>> price^1.0
>> attrs^5.0
>>
>> expandedGender^0.5
>>
>>
>> ?
>>
>>
>> attrs^3 brandName^10.0 productNameSearch^8.0
>> productDescription^2.0 personality^4.0 subCategory^12.0 category^10.0
>> productType^8.0
>>
>>
>> ?
>>
>>
>> productId, productName, price, originalPrice,
>> brandNameFacet, productRating, imageUrl, productUrl, isNew, onSale, styleId
>>
>>
>> 100%
>> 1
>> 5
>> *:*
>>
>> ?
>>
>> brandNameFacet,productTypeFacet,productName,categoryFacet,subCategoryFacet,p
>> ersonalityFacet,colorFacet,heelHeight,expandedGender
>>
>> 1
>> 1
>>
>> ?
>>
>> spellcheck
>>
>>
>>
>> --
>> Jeff Newburn
>> Software Engineer, Zappos.com
>> jnewb...@zappos.com - 702-943-7562
>>
>>
>>> From: Erik Hatcher
>>> Reply-To:
>>> Date: Wed, 22 Jul 2009 00:36:30 -0400
>>> To:
>>> Subject: Re: Random Slowness
>>>
>>>
>>> On Jul 21, 2009, at 6:52 PM, Jeff Newburn wrote:
>>>
>>>> We are experiencing random slowness on certain queries. I have been
>>>> unable
>>>> to diagnose what the issue is. We are using SOLR 1.4 and 99.99% of
>>>> queries
>>>> return in under 250 ms. The remaining queries are returning in 2-5
>>>> seconds
>>>> for no apparent reason. There does not seem to be any commonality
>>>> between
>>>> the queries. This problem also includes admin system queries. Any
>>>> help or
>>>> direction would be much appreciated.
>>>
>>> Do you experience the same slow speeds when you manually issue those
>>> queries? In other words, is it repeatable? If so, try
>>> &debugQuery=true and see the component timings and where the time is
>>> going.
>>>
>>> What's the query parsing too? Anything unusually large due to synonym
>>> lists or something like that?
>>>
>>> What about your filter cache - how's it looking when these slow
>>> queries take place? evictions > 0?
>>>
>>>> params
>>>> ={facet=true&facet.mincount=1&facet.limit=-1&wt=javabin&rows=0&facet.s
>>>> ort
>>>> =
>>>> true
>>>> &start=0&q=shoes&facet.field=colorFacet&facet.field=brandNameFacet&f
>>>> acet
>>>> .field
>>>> =heelHeight&facet.field=attrFacet_Style&qt=dismax&fq=productTypeFa
>>>> cet:Shoes
>>>> &fq=gender:Womens&fq=categoryFacet:Sandals&fq=width:EE&fq=size:10.5
>>>> &fq=priceFacet:"$100.00+and+Under"&fq=personalityFacet:Sexy} hits=19
>>>> status=0 QTime=3689
>>>
>>> What's the config of your dismax handler look like?
>>>
>>> Erik
>>>
>>
>>
Re: Random Slowness
I haven't read this whole thread, so maybe it's already come up. Have
you turned on the garbage collection logging to see if the jvm is busy
cleaning up when you are seeing the slowness? Maybe the jvm is
struggling to keep the heap size within a particular limit?
//Ed
On Wed, Jul 22, 2009 at 10:22 AM, Jeff Newburn wrote:
> We can never reproduce the slowness with the same query. As soon as we try
> to run them again they are fine. I have even tried running the same query
> the next day and it is fine.
>
> All of our requests go through our dismax handler which is part of why it is
> so weird. Most queries are fine, however just occasionally they aren't.
> Additionally, why would the command=details command also go slow? That
> seems like a server issue.
>
> It appears that for FieldValueCache and FilterCache we have no evictions,
> but for queryResultCache and DocumentCache there are a good number of
> evictions. How would I help lower the evictions to see if that is the
> problem?
>
> Dismax Config below:
> default="true">
> ?
>
> explicit
> 0.5
> ?
>
>
> productId^10.0
>
> personality^8.0
> subCategory^8.0
> category^6.0
> productType^5.0
>
> brandName^1.0
> realBrandName^1.0
> productNameSearch^1.0
>
> size^1.2
> width^1.0
> heelHeight^1.0
>
> productDescription^1.0
> color^10.0
> price^1.0
> attrs^5.0
>
> expandedGender^0.5
>
>
> ?
>
>
> attrs^3 brandName^10.0 productNameSearch^8.0
> productDescription^2.0 personality^4.0 subCategory^12.0 category^10.0
> productType^8.0
>
>
> ?
>
>
> productId, productName, price, originalPrice,
> brandNameFacet, productRating, imageUrl, productUrl, isNew, onSale, styleId
>
>
> 100%
> 1
> 5
> *:*
>
> ?
>
> brandNameFacet,productTypeFacet,productName,categoryFacet,subCategoryFacet,p
> ersonalityFacet,colorFacet,heelHeight,expandedGender
>
> 1
> 1
>
> ?
>
> spellcheck
>
>
>
> --
> Jeff Newburn
> Software Engineer, Zappos.com
> jnewb...@zappos.com - 702-943-7562
>
>
>> From: Erik Hatcher
>> Reply-To:
>> Date: Wed, 22 Jul 2009 00:36:30 -0400
>> To:
>> Subject: Re: Random Slowness
>>
>>
>> On Jul 21, 2009, at 6:52 PM, Jeff Newburn wrote:
>>
>>> We are experiencing random slowness on certain queries. I have been
>>> unable
>>> to diagnose what the issue is. We are using SOLR 1.4 and 99.99% of
>>> queries
>>> return in under 250 ms. The remaining queries are returning in 2-5
>>> seconds
>>> for no apparent reason. There does not seem to be any commonality
>>> between
>>> the queries. This problem also includes admin system queries. Any
>>> help or
>>> direction would be much appreciated.
>>
>> Do you experience the same slow speeds when you manually issue those
>> queries? In other words, is it repeatable? If so, try
>> &debugQuery=true and see the component timings and where the time is
>> going.
>>
>> What's the query parsing too? Anything unusually large due to synonym
>> lists or something like that?
>>
>> What about your filter cache - how's it looking when these slow
>> queries take place? evictions > 0?
>>
>>> params
>>> ={facet=true&facet.mincount=1&facet.limit=-1&wt=javabin&rows=0&facet.s
>>> ort
>>> =
>>> true
>>> &start=0&q=shoes&facet.field=colorFacet&facet.field=brandNameFacet&f
>>> acet
>>> .field
>>> =heelHeight&facet.field=attrFacet_Style&qt=dismax&fq=productTypeFa
>>> cet:Shoes
>>> &fq=gender:Womens&fq=categoryFacet:Sandals&fq=width:EE&fq=size:10.5
>>> &fq=priceFacet:"$100.00+and+Under"&fq=personalityFacet:Sexy} hits=19
>>> status=0 QTime=3689
>>
>> What's the config of your dismax handler look like?
>>
>> Erik
>>
>
>
Re: Random Slowness
We can never reproduce the slowness with the same query. As soon as we try
to run them again they are fine. I have even tried running the same query
the next day and it is fine.
All of our requests go through our dismax handler which is part of why it is
so weird. Most queries are fine, however just occasionally they aren't.
Additionally, why would the command=details command also go slow? That
seems like a server issue.
It appears that for FieldValueCache and FilterCache we have no evictions,
but for queryResultCache and DocumentCache there are a good number of
evictions. How would I help lower the evictions to see if that is the
problem?
Dismax Config below:
?
explicit
0.5
?
productId^10.0
personality^8.0
subCategory^8.0
category^6.0
productType^5.0
brandName^1.0
realBrandName^1.0
productNameSearch^1.0
size^1.2
width^1.0
heelHeight^1.0
productDescription^1.0
color^10.0
price^1.0
attrs^5.0
expandedGender^0.5
?
attrs^3 brandName^10.0 productNameSearch^8.0
productDescription^2.0 personality^4.0 subCategory^12.0 category^10.0
productType^8.0
?
productId, productName, price, originalPrice,
brandNameFacet, productRating, imageUrl, productUrl, isNew, onSale, styleId
100%
1
5
*:*
?
brandNameFacet,productTypeFacet,productName,categoryFacet,subCategoryFacet,p
ersonalityFacet,colorFacet,heelHeight,expandedGender
1
1
?
spellcheck
--
Jeff Newburn
Software Engineer, Zappos.com
jnewb...@zappos.com - 702-943-7562
> From: Erik Hatcher
> Reply-To:
> Date: Wed, 22 Jul 2009 00:36:30 -0400
> To:
> Subject: Re: Random Slowness
>
>
> On Jul 21, 2009, at 6:52 PM, Jeff Newburn wrote:
>
>> We are experiencing random slowness on certain queries. I have been
>> unable
>> to diagnose what the issue is. We are using SOLR 1.4 and 99.99% of
>> queries
>> return in under 250 ms. The remaining queries are returning in 2-5
>> seconds
>> for no apparent reason. There does not seem to be any commonality
>> between
>> the queries. This problem also includes admin system queries. Any
>> help or
>> direction would be much appreciated.
>
> Do you experience the same slow speeds when you manually issue those
> queries? In other words, is it repeatable? If so, try
> &debugQuery=true and see the component timings and where the time is
> going.
>
> What's the query parsing too? Anything unusually large due to synonym
> lists or something like that?
>
> What about your filter cache - how's it looking when these slow
> queries take place? evictions > 0?
>
>> params
>> ={facet=true&facet.mincount=1&facet.limit=-1&wt=javabin&rows=0&facet.s
>> ort
>> =
>> true
>> &start=0&q=shoes&facet.field=colorFacet&facet.field=brandNameFacet&f
>> acet
>> .field
>> =heelHeight&facet.field=attrFacet_Style&qt=dismax&fq=productTypeFa
>> cet:Shoes
>> &fq=gender:Womens&fq=categoryFacet:Sandals&fq=width:EE&fq=size:10.5
>> &fq=priceFacet:"$100.00+and+Under"&fq=personalityFacet:Sexy} hits=19
>> status=0 QTime=3689
>
> What's the config of your dismax handler look like?
>
> Erik
>
Re: Random Slowness
On Jul 21, 2009, at 6:52 PM, Jeff Newburn wrote:
We are experiencing random slowness on certain queries. I have been
unable
to diagnose what the issue is. We are using SOLR 1.4 and 99.99% of
queries
return in under 250 ms. The remaining queries are returning in 2-5
seconds
for no apparent reason. There does not seem to be any commonality
between
the queries. This problem also includes admin system queries. Any
help or
direction would be much appreciated.
Do you experience the same slow speeds when you manually issue those
queries? In other words, is it repeatable? If so, try
&debugQuery=true and see the component timings and where the time is
going.
What's the query parsing too? Anything unusually large due to synonym
lists or something like that?
What about your filter cache - how's it looking when these slow
queries take place? evictions > 0?
params
={facet=true&facet.mincount=1&facet.limit=-1&wt=javabin&rows=0&facet.s
ort
=
true
&start=0&q=shoes&facet.field=colorFacet&facet.field=brandNameFacet&f
acet
.field
=heelHeight&facet.field=attrFacet_Style&qt=dismax&fq=productTypeFa
cet:Shoes
&fq=gender:Womens&fq=categoryFacet:Sandals&fq=width:EE&fq=size:10.5
&fq=priceFacet:"$100.00+and+Under"&fq=personalityFacet:Sexy} hits=19
status=0 QTime=3689
What's the config of your dismax handler look like?
Erik
Random Slowness
We are experiencing random slowness on certain queries. I have been unable
to diagnose what the issue is. We are using SOLR 1.4 and 99.99% of queries
return in under 250 ms. The remaining queries are returning in 2-5 seconds
for no apparent reason. There does not seem to be any commonality between
the queries. This problem also includes admin system queries. Any help or
direction would be much appreciated.
Specs:
Solr 1.4
Tomcat Server
4 cores
Largest core 155,000 documents.
Logs:
INFO: [zeta-main] webapp=null path=null params={command=details} status=0
QTime=1276
INFO: [zeta-main] webapp=null path=null params={command=details} status=0
QTime=1144
INFO: [zeta-main] webapp=null path=null params={command=details} status=0
QTime=1285
INFO: [zeta-main] webapp=/solr path=/select
params={facet=true&facet.mincount=1&facet.limit=-1&wt=javabin&rows=0&facet.s
ort=true&start=0&q=shoes&facet.field=colorFacet&facet.field=brandNameFacet&f
acet.field=heelHeight&facet.field=attrFacet_Style&qt=dismax&fq=productTypeFa
cet:Shoes&fq=gender:Womens&fq=categoryFacet:Sandals&fq=width:EE&fq=size:10.5
&fq=priceFacet:"$100.00+and+Under"&fq=personalityFacet:Sexy} hits=19
status=0 QTime=3689
INFO: [zeta-main] webapp=/solr path=/select
params={wt=javabin&rows=100&facet.sort=true&start=0&q=shoes&qt=dismax&fq=pro
ductTypeFacet:Shoes&fq=gender:Womens&fq=size:8&fq=width:D&fq=brandNameFacet:
Dansko} hits=8 status=0 QTime=3566
INFO: [zeta-main] webapp=/solr path=/select
params={wt=javabin&rows=100&facet.sort=true&start=0&q=shoes&qt=dismax&fq=gen
der:Womens&fq=productTypeFacet:Shoes&fq=subCategoryFacet:Heels&fq=categoryFa
cet:Shoes&fq=size:10} hits=5409 status=0 QTime=3348
INFO: [zeta-main] webapp=/solr path=/select
params={wt=javabin&rows=100&facet.sort=true&start=100&q=shoes&qt=dismax&fq=p
roductTypeFacet:Shoes&fq=gender:Womens&fq=personalityFacet:Dress&fq=category
Facet:Shoes&fq=size:10&fq=heelHeight:"Medium+(1+3/8in+-+2+1/2in)"} hits=1129
status=0 QTime=3285
INFO: [zeta-main] webapp=/solr path=/select
params={wt=javabin&rows=100&facet.sort=true&start=200&q=shoes&qt=dismax&fq=p
roductTypeFacet:Shoes&fq=gender:Womens&fq=categoryFacet:Shoes&fq=subCategory
Facet:Heels&fq=personalityFacet:Dress&fq=attrFacet_Style:Pump&fq=size:5}
hits=644 status=0 QTime=3750
INFO: [6pm-main] webapp=/solr path=/select
params={wt=javabin&rows=100&facet.sort=true&start=0&q=shoes&qt=dismax&fq=exp
andedGender:Kids&fq=productTypeFacet:Shoes&fq=gender:girls&fq=brandNameFacet
:"UGG+Kids"} hits=17 status=0 QTime=3789
--
Jeff Newburn
Software Engineer, Zappos.com
jnewb...@zappos.com - 702-943-7562
