You are viewing a plain text version of this content. The canonical link for it is here.
Posted to solr-user@lucene.apache.org by Dalton Gooding <da...@yahoo.com.au.INVALID> on 2016/10/06 21:56:50 UTC
newSearcher autowarming queries in solrconfig.xml run but does not
appear to warm cache
After setting a number of newSearcher and firstSearcher queries, I can see in the console logs that the queries are run, but when I run the same query against the new searcher (using CuRL), I get a slow response time for the first run.
Config:
<listener event="newSearcher" class="solr.QuerySenderListener"> <arr name="queries"> <lst> <str name="fq">DataType_s:Product</str> <str name="fq">WebSections_ms:house</str> <str name="fq">{!tag=current_group}GroupIds_ms:*</str>
<str name="facet">true</str> <str name="facet.field">BrandID_s</str> <str name="facet.query">Price_2_f:[* TO *]</str> <str name="facet.query">Price_3_f:[* TO *]</str> <str name="facet.query">Price_4_f:[* TO *]</str> <str name="facet.query">Price_5_f:[* TO *]</str> <str name="facet.query">Price_6_f:[* TO *]</str> <str name="facet.query">Price_7_f:[* TO *]</str> <str name="facet.query">Price_8_f:[* TO *]</str> <str name="facet.mincount">1</str> <str name="facet.method">fc</str> <str name="wt">json</str> <str name="json.nl">map</str> <str name="q">(title:* OR text:*)</str> <str name="start">0</str> <str name="rows">20</str> </lst> </arr> </listener>
Console log:
INFO (searcherExecutor-7-thread-1-processing-x:core1) [ x:core1] o.a.s.c.S.Request [core1] webapp=null path=null params={facet=true&facet.mincount=1&start=0&facet.query=Price_2_f:[*+TO+*]&facet.query=Price_3_f:[*+TO+*]&facet.query=Price_4_f:[*+TO+*]&facet.query=Price_5_f:[*+TO+*]&facet.query=Price_6_f:[*+TO+*]&facet.query=Price_7_f:[*+TO+*]&facet.query=Price_8_f:[*+TO+*]&event=newSearcher&q=(title:*+OR+text:*)&distrib=false&json.nl=map&facet.field=BrandID_s&wt=json&facet.method=fc&fq=DataType_s:Product&fq=WebSections_ms:house&fq=VisibleOnline_ms:7&fq={!tag%3Dcurrent_group}GroupIds_ms:*&rows=20} hits=2549 status=0 QTime=1263
If I run the same query after the index has registered I see a QTime of over a second, the second time I run the query I see around 80ms. This leads me to believe the warming did not occur or the query was not commited to cache on start up of the new searcher.
Can someone please advise on how to use the newSearcher queries to effectively warm SolR caches. Should I see an improved response for the first time I run the query if the same query has been used as a newSearcher query?
Cheers,
Dalton
Re: newSearcher autowarming queries in solrconfig.xml run but does
not appear to warm cache
Posted by Dalton Gooding <da...@yahoo.com.au.INVALID>.
Erick,
Thanks very much for your help so far with this one. I have captured the logs from a commit which shows a commit and new searcher starting.
It appears a few ERROR's are amongst the logs and a few uninverting lines.
The query is a very basic query as shown below:
<lst> <str name="fq">DataType_s:Product</str>
<str name="fq">WebSections_ms:house</str>
<str name="fq">VisibleOnline_ms:NAT</str>
<str name="q">SS_Stage_ms:Live</str>
<str name="start">0</str>
<str name="rows">20</str>
</lst>
INFO (qtp755840090-55) [ x:core1] o.a.s.c.SolrCore SolrDeletionPolicy.onCommit: commits: num=2
commit{dir=NRTCachingDirectory(MMapDirectory@/var/solr/data/core1/data/index.20131212092900012 lockFactory=org.apache.lucene.store.NativeFSLockFactory@8815140; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_9kgw,generation=446432}
commit{dir=NRTCachingDirectory(MMapDirectory@/var/solr/data/core1/data/index.20131212092900012 lockFactory=org.apache.lucene.store.NativeFSLockFactory@8815140; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_9kgx,generation=446433}
INFO (qtp755840090-55) [ x:core1] o.a.s.c.SolrCore newest commit generation = 446433
INFO (qtp755840090-55) [ x:core1] o.a.s.s.SolrIndexSearcher Opening Searcher@63f1fac[core1] main
INFO (searcherExecutor-7-thread-1-processing-x:core1) [ x:core1] o.a.s.c.SolrCore QuerySenderListener sending requests to Searcher@63f1fac[core1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a3p4(5.3.1):C313761/58754:delGen=2073) Uninverting(_a7bs(5.3.1):c22601/9516:delGen=608) Uninverting(_a7np(5.3.1):C37794/14987:delGen=463) Uninverting(_aa7h(5.3.1):c13906/163:delGen=57) Uninverting(_a7u7(5.3.1):c5968/504:delGen=89) Uninverting(_a7yt(5.3.1):c2643/426:delGen=39) Uninverting(_aafw(5.3.1):c313/27:delGen=2) Uninverting(_aajf(5.3.1):c355/14:delGen=3) Uninverting(_aaqa(5.3.1):c195/1:delGen=1) Uninverting(_aapg(5.3.1):c279/3:delGen=3) Uninverting(_aahr(5.3.1):c262/5:delGen=1) Uninverting(_aafa(5.3.1):c265/2:delGen=1) Uninverting(_aap3(5.3.1):c252/2:delGen=2) Uninverting(_aaqb(5.3.1):C1) Uninverting(_aaqd(5.3.1):C1) Uninverting(_aaqh(5.3.1):C1) Uninverting(_aaqj(5.3.1):C1) Uninverting(_aaqm(5.3.1):C2/1:delGen=1) Uninverting(_aaqo(5.3.1):C1) Uninverting(_aaqq(5.3.1):C1) Uninverting(_aaqs(5.3.1):C1)))}
ERROR (searcherExecutor-7-thread-1-processing-x:core1) [ x:core1] o.a.s.c.SolrCore Previous SolrRequestInfo was not closed! req=wt=json
ERROR (searcherExecutor-7-thread-1-processing-x:core1) [ x:core1] o.a.s.c.SolrCore prev == info : false
INFO (searcherExecutor-7-thread-1-processing-x:core1) [ x:core1] o.a.s.c.S.Request [core1] webapp=null path=null params={start=0&event=newSearcher&q=SS_Stage_ms:Live&distrib=false&fq=DataType_s:Product&fq=WebSections_ms:house&fq=VisibleOnline_ms:NAT&rows=20} hits=2541 status=0 QTime=18
INFO (searcherExecutor-7-thread-1-processing-x:core1) [ x:core1] o.a.s.c.SolrCore QuerySenderListener done.
INFO (searcherExecutor-7-thread-1-processing-x:core1) [ x:core1] o.a.s.c.SolrCore [core1] Registered new searcher Searcher@63f1fac[core1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a3p4(5.3.1):C313761/58754:delGen=2073) Uninverting(_a7bs(5.3.1):c22601/9516:delGen=608) Uninverting(_a7np(5.3.1):C37794/14987:delGen=463) Uninverting(_aa7h(5.3.1):c13906/163:delGen=57) Uninverting(_a7u7(5.3.1):c5968/504:delGen=89) Uninverting(_a7yt(5.3.1):c2643/426:delGen=39) Uninverting(_aafw(5.3.1):c313/27:delGen=2) Uninverting(_aajf(5.3.1):c355/14:delGen=3) Uninverting(_aaqa(5.3.1):c195/1:delGen=1) Uninverting(_aapg(5.3.1):c279/3:delGen=3) Uninverting(_aahr(5.3.1):c262/5:delGen=1) Uninverting(_aafa(5.3.1):c265/2:delGen=1) Uninverting(_aap3(5.3.1):c252/2:delGen=2) Uninverting(_aaqb(5.3.1):C1) Uninverting(_aaqd(5.3.1):C1) Uninverting(_aaqh(5.3.1):C1) Uninverting(_aaqj(5.3.1):C1) Uninverting(_aaqm(5.3.1):C2/1:delGen=1) Uninverting(_aaqo(5.3.1):C1) Uninverting(_aaqq(5.3.1):C1) Uninverting(_aaqs(5.3.1):C1)))}
INFO (qtp755840090-55) [ x:core1] o.a.s.u.UpdateHandler end_commit_flush
On Tuesday, 18 October 2016, 0:49, Erick Erickson <er...@gmail.com> wrote:
Wow, wouldn't it be useful if the name of the field was dumped in the
message ;)...
You should see a query happen just before that message in the log
file. It won't quite be in the same format as a URL, but it's
reasonably easy to figure out.
Uninverting happens as a result of
> sorting
> faceting
> grouping
> ???
So the crude approach wold be to find the query(s) that precede this
then break it apart submitting one of the above operations from the
query in question at a time while tailing the logs.
And by "after the warming queries", I'm assuming that the searcher has
successfully opened (there'll be a message in the log).
BTW, DocValues fields are strongly recommended for any field that gets
uninverted.
Best,
Erick
On Sun, Oct 16, 2016 at 10:28 PM, Dalton Gooding
<da...@yahoo.com.au> wrote:
> Erick,
>
> I think you might have nailed it.
>
> After the three warming queries, I get the below when registering a new
> searcher. How can I find out what I am missing in my warming queries?
>
> Registered new searcher Searcher@15cdc368[core1]
> main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a3p4(5.3.1):C313761/57815:delGen=1722)
> Uninverting(_a7bs(5.3.1):c22601/8393:delGen=464)
> Uninverting(_a7np(5.3.1):C37794/13471:delGen=244)
> Uninverting(_a7rp(5.3.1):c2490/760:delGen=77)
> Uninverting(_a7u7(5.3.1):c5968/338:delGen=27)
> Uninverting(_a7rz(5.3.1):c4306/1718:delGen=94)
> Uninverting(_a806(5.3.1):c1734/7:delGen=6)
> Uninverting(_a7tx(5.3.1):c1900/67:delGen=10)
> Uninverting(_a7tn(5.3.1):c1900/24:delGen=9)
> Uninverting(_a7yt(5.3.1):c2643/144:delGen=8)
> Uninverting(_a7zn(5.3.1):c1595/2:delGen=2) Uninverting(_a82v(5.3.1):c31)
> Uninverting(_a843(5.3.1):c23/3:delGen=1)
> Uninverting(_a844(5.3.1):C3/1:delGen=1) Uninverting(_a846(5.3.1):C1)
> Uninverting(_a848(5.3.1):C5/1:delGen=1) Uninverting(_a84a(5.3.1):C1)
> Uninverting(_a84c(5.3.1):C1)))}
>
>
> On Friday, 14 October 2016, 9:50, Erick Erickson <er...@gmail.com>
> wrote:
>
>
> Well, that's a puzzle, sorry I don't have a good answer.
>
> The fact that your newSearcher event to be fired _should_ populate
> the low-level caches. BTW, what's your autowarm count on filterCache and
> queryResultCache? Have you tried setting them to non-zero values? Those
> won't help when you first start Solr, but that should be rare.
>
> Do note that your newSearcher events should mention a series of different
> values
> from the fields in question.
>
> Actually here's what I'd do. Look carefully in your Solr log after you
> do a commit and
> particularly when you fire your first query after the new searcher is
> opened. Do you see
> any suspicious messages like "Uninverting field" or the like? That
> would indicate sorting
> or faceting on a field that wasn't warmed by the newSearcher because
> you didn't mention
> sorting or faceting or whatever in your warming query.
>
> Can we see the newSearcher entry and the query you say is "similar"
> but slow. My _guess_
> is that some innocent-seeming difference between the two is the issue.
>
> Best,
> Erick
>
> On Sun, Oct 9, 2016 at 7:08 PM, Dalton Gooding
> <da...@yahoo.com.au> wrote:
>> Erick,
>>
>> I have tried tuning the queries with some limited success. I still get
>> drastic differences between the first time I fire my warming query (after
>> newSearcher ran query) and the second time, or any variant of the query
>> i.e.
>> removing fields or changing parameters, it runs much faster.
>>
>> I am not sure what I am missing here, I put a query into the newSearcher
>> section that runs fine, but the exact same query run after warming still
>> takes the full time of a un-warmed query.
>>
>> Can you break it down to the most basic type of newSearcher query to try
>> and
>> shrink the gap between first query and subsequent queries sent?
>>
>> I cannot see why sending the same query after a newSearcher is slow, when
>> subsequent queries run faster. I figured this was the idea of the
>> newSearcher stanza's.
>>
>>
>> On Friday, 7 October 2016, 14:45, Erick Erickson <er...@gmail.com>
>> wrote:
>>
>>
>> Replying on the public thread, somehow your mail was sent to me privately.
>>
>> Pasted your email to me below for others.
>>
>> You are still confusing documents and results. Forget about the rows
>> parameter, for this discussion it's irrelevant.
>>
>> The QTime is the time spent searching. It is unaffected by whether a
>> document is in the documentCache or not.
>> It _solely_ measures the time that Solr/Lucene take to find the top N
>> documents (where N is the rows param) and
>> record their internal Lucene doc ID.
>>
>> Increasing the rows or the document cache won't change anything about
>> the QTime. The documentCache is
>> totally the wrong place to focus.
>>
>>
>> The response when you re-submit the query suggests that getting the
>> top N docs' internal Lucene ID is
>> fetched from the queryResultCache. Changing the window size is also
>> irrelevant to this discussion. If you
>> vary the query even slightly you won't hit the queryResultCache. A
>> very easy way to check this is the
>> admin UI>>select core>>plugins/stats>>QueryHandler and then probably
>> the "select" handler. If you see
>> the hits go up after the fast query then you're getting the results
>> from the querResultCache.
>>
>> What _is_ relevant is populating the low-level Lucene caches with
>> values from the indexed terms. My
>> contention is that this is not happening with match-all queries, i.e.
>> field:* or field:[* TO *] because in
>> those cases, a doc matches or doesn't based on whether it has anything
>> in the field. There's no point
>> in finding values since it doesn't matter anyway. And "finding values"
>> means reading indexed terms
>> from disk into low-level Lucene caches.
>>
>> When I say "populate the low-level Lucene caches", what I'm really
>> talking about is reading them from
>> disk into your physical memory via MMapDirectory, see Uwe's excellent
>> blog:
>> http://blog.thetaphi.de/2012/07/use-lucenes-mmapdirectory-on-64bit.html
>>
>> So the suggestion is that you use real values from your index or
>> possibly ranges is so that part or all
>> of your disk files get read into MMapDirectorySpace via the first or
>> new Searcher event.
>>
>> Please just give it a try. My bet is that you'll see your QTime values
>> first time after autowarming
>> go down. Significantly. Be sure to use a wide variety of different
>> values for autowarming.
>>
>> BTW, the autowarmCounts in solrconfig.xml filterCache and
>> queryResultCache are intended
>> to warm by using the last N fq or q clauses on the theory that the
>> most recent N are predictive
>> of the next N.
>>
>> Best,
>> Erick
>>
>>
>> ***************
>>
>> I believe the return time back to the command line from the curl
>> command and the QTime as shown below
>>
>> time curl -v
>>
>> 'http://<SolR>/solr/core1/select?fq=DataType_s%3AProduct&fq=WebSections_ms%3Ahouse&fq=%28VisibleOnline_ms%3ANAT+OR+VisibleOnline_ms%3A7%29&fq=%7B%21tag%3Dcurrent_group%7DGroupIds_ms%3A458&sort=SalesRank_f+desc&facet=true&facet.field=%7B%21ex%3Dcurrent_group%7Dattr_GroupLevel0&facet.field=BrandID_s&facet.field=%7B%21ex%3Dcurrent_group%7Dattr_GroupLevel2&facet.field=%7B%21ex%3Dcurrent_group%7Dattr_GroupLevel1&facet.field=SubBrandID_s&facet.field=ProductAttr_967_ms&facet.field=ProductAttr_NEG21_ms&facet.field=ProductAttr_1852_ms&facet.query=Price_7_f%3A%5B%2A+TO+%2A%5D&facet.query=Price_2_f%3A%5B%2A+TO+%2A%5D&facet.query=Price_3_f%3A%5B%2A+TO+%2A%5D&facet.query=Price_4_f%3A%5B%2A+TO+%2A%5D&facet.query=Price_5_f%3A%5B%2A+TO+%2A%5D&facet.query=Price_6_f%3A%5B%2A+TO+%2A%5D&facet.mincount=1&wt=json&json.nl=map&q=%28title%3A%2A+OR+text%3A%2A%29+AND+%28ms%3ALive%29&start=0&rows=24'
>>
>> real 0m1.436s
>> user 0m0.001s
>> sys 0m0.006s
>>
>> "QTime":1387
>>
>> From what you suggested, changing the rows value from 20 to something
>> greater should add more documents to the cache. Injunction with tuning
>> the queries to remove the * wild card, this should provide a better
>> warming query?
>>
>> Should I also increase the queryResultWindowSize in the solrconfig.xml
>> to help built out the cache?
>>
>> Cheers,
>>
>> Guy
>>
>>
>>
>>
>>
>> On Thu, Oct 6, 2016 at 4:43 PM, Dalton Gooding
>> <da...@yahoo.com.au> wrote:
>>> Erick,
>>>
>>> Thanks for the response. After I run the initial query and get a long
>>> response time, if I change the query to remove or add additional query
>>> statements, I find the speed is good.
>>>
>>> If I run the modified query after a new searcher has registered, the
>>> response is slow but after the modified query has been completed, the
>>> warming query sent from CuRl is much faster. I assume it is because the
>>> document cache has updated with the documents from the modified query. A
>>> large number of our queries work with the same document set, I am trying
>>> to
>>> get a warming query to populate the document cache to be as big as
>>> feasible.
>>>
>>> Should the firstSearcher and newSearcher warm the document cache?
>>>
>>>
>>> On Friday, 7 October 2016, 9:31, Erick Erickson <er...@gmail.com>
>>> wrote:
>>>
>>>
>>> Submitting the exact same query twice will return results from the
>>> queryResultCache. I'm not entirely
>>> sure that the firstSearcher events get put into the cache.
>>>
>>> So if you change the query even slighty my guess is that you'll see
>>> response times very close to your
>>> original ones of over a second.
>>>
>>> Best,
>>> Erick
>>>
>>> On Thu, Oct 6, 2016 at 2:56 PM, Dalton Gooding
>>> <da...@yahoo.com.au.invalid> wrote:
>>>> After setting a number of newSearcher and firstSearcher queries, I can
>>>> see
>>>> in the console logs that the queries are run, but when I run the same
>>>> query
>>>> against the new searcher (using CuRL), I get a slow response time for
>>>> the
>>>> first run.
>>>>
>>>> Config:
>>>> <listener event="newSearcher" class="solr.QuerySenderListener">
>>>> <arr name="queries"> <lst> <str
>>>> name="fq">DataType_s:Product</str>
>>>> <str name="fq">WebSections_ms:house</str> <str
>>>> name="fq">{!tag=current_group}GroupIds_ms:*</str>
>>>> <str name="facet">true</str> <str
>>>> name="facet.field">BrandID_s</str> <str
>>>> name="facet.query">Price_2_f:[* TO *]</str> <str
>>>> name="facet.query">Price_3_f:[* TO *]</str> <str
>>>> name="facet.query">Price_4_f:[* TO *]</str> <str
>>>> name="facet.query">Price_5_f:[* TO *]</str> <str
>>>> name="facet.query">Price_6_f:[* TO *]</str> <str
>>>> name="facet.query">Price_7_f:[* TO *]</str> <str
>>>> name="facet.query">Price_8_f:[* TO *]</str> <str
>>>> name="facet.mincount">1</str> <str
>>>> name="facet.method">fc</str>
>>>> <str name="wt">json</str> <str name="json.nl">map</str>
>>>> <str name="q">(title:* OR text:*)</str> <str
>>>> name="start">0</str> <str name="rows">20</str>
>>>> </lst>
>>>> </arr> </listener>
>>>>
>>>> Console log:
>>>> INFO (searcherExecutor-7-thread-1-processing-x:core1) [ x:core1]
>>>> o.a.s.c.S.Request [core1] webapp=null path=null
>>>>
>>>>
>>>> params={facet=true&facet.mincount=1&start=0&facet.query=Price_2_f:[*+TO+*]&facet.query=Price_3_f:[*+TO+*]&facet.query=Price_4_f:[*+TO+*]&facet.query=Price_5_f:[*+TO+*]&facet.query=Price_6_f:[*+TO+*]&facet.query=Price_7_f:[*+TO+*]&facet.query=Price_8_f:[*+TO+*]&event=newSearcher&q=(title:*+OR+text:*)&distrib=false&json.nl=map&facet.field=BrandID_s&wt=json&facet.method=fc&fq=DataType_s:Product&fq=WebSections_ms:house&fq=VisibleOnline_ms:7&fq={!tag%3Dcurrent_group}GroupIds_ms:*&rows=20}
>>>> hits=2549 status=0 QTime=1263
>>>>
>>>>
>>>> If I run the same query after the index has registered I see a QTime of
>>>> over a second, the second time I run the query I see around 80ms. This
>>>> leads
>>>> me to believe the warming did not occur or the query was not commited to
>>>> cache on start up of the new searcher.
>>>> Can someone please advise on how to use the newSearcher queries to
>>>> effectively warm SolR caches. Should I see an improved response for the
>>>> first time I run the query if the same query has been used as a
>>>> newSearcher
>>>> query?
>>>> Cheers,
>>>> Dalton
>>>
>>>
>>
>> On Thu, Oct 6, 2016 at 4:43 PM, Dalton Gooding
>> <da...@yahoo.com.au> wrote:
>>> Erick,
>>>
>>> Thanks for the response. After I run the initial query and get a long
>>> response time, if I change the query to remove or add additional query
>>> statements, I find the speed is good.
>>>
>>> If I run the modified query after a new searcher has registered, the
>>> response is slow but after the modified query has been completed, the
>>> warming query sent from CuRl is much faster. I assume it is because the
>>> document cache has updated with the documents from the modified query. A
>>> large number of our queries work with the same document set, I am trying
>>> to
>>> get a warming query to populate the document cache to be as big as
>>> feasible.
>>>
>>> Should the firstSearcher and newSearcher warm the document cache?
>>>
>>>
>>> On Friday, 7 October 2016, 9:31, Erick Erickson <er...@gmail.com>
>>> wrote:
>>>
>>>
>>> Submitting the exact same query twice will return results from the
>>> queryResultCache. I'm not entirely
>>> sure that the firstSearcher events get put into the cache.
>>>
>>> So if you change the query even slighty my guess is that you'll see
>>> response times very close to your
>>> original ones of over a second.
>>>
>>> Best,
>>> Erick
>>>
>>>
>>> On Thu, Oct 6, 2016 at 2:56 PM, Dalton Gooding
>>> <da...@yahoo.com.au.invalid> wrote:
>>>> After setting a number of newSearcher and firstSearcher queries, I can
>>>> see
>>>> in the console logs that the queries are run, but when I run the same
>>>> query
>>>> against the new searcher (using CuRL), I get a slow response time for
>>>> the
>>>> first run.
>>>>
>>>> Config:
>>>> <listener event="newSearcher" class="solr.QuerySenderListener">
>>>> <arr name="queries"> <lst> <str
>>>> name="fq">DataType_s:Product</str>
>>>> <str name="fq">WebSections_ms:house</str> <str
>>>> name="fq">{!tag=current_group}GroupIds_ms:*</str>
>>>> <str name="facet">true</str> <str
>>>> name="facet.field">BrandID_s</str> <str
>>>> name="facet.query">Price_2_f:[* TO *]</str> <str
>>>> name="facet.query">Price_3_f:[* TO *]</str> <str
>>>> name="facet.query">Price_4_f:[* TO *]</str> <str
>>>> name="facet.query">Price_5_f:[* TO *]</str> <str
>>>> name="facet.query">Price_6_f:[* TO *]</str> <str
>>>> name="facet.query">Price_7_f:[* TO *]</str> <str
>>>> name="facet.query">Price_8_f:[* TO *]</str> <str
>>>> name="facet.mincount">1</str> <str
>>>> name="facet.method">fc</str>
>>>> <str name="wt">json</str> <str name="json.nl">map</str>
>>>> <str name="q">(title:* OR text:*)</str> <str
>>>> name="start">0</str> <str name="rows">20</str>
>>>> </lst>
>>>> </arr> </listener>
>>>>
>>>> Console log:
>>>> INFO (searcherExecutor-7-thread-1-processing-x:core1) [ x:core1]
>>>> o.a.s.c.S.Request [core1] webapp=null path=null
>>>>
>>>>
>>>> params={facet=true&facet.mincount=1&start=0&facet.query=Price_2_f:[*+TO+*]&facet.query=Price_3_f:[*+TO+*]&facet.query=Price_4_f:[*+TO+*]&facet.query=Price_5_f:[*+TO+*]&facet.query=Price_6_f:[*+TO+*]&facet.query=Price_7_f:[*+TO+*]&facet.query=Price_8_f:[*+TO+*]&event=newSearcher&q=(title:*+OR+text:*)&distrib=false&json.nl=map&facet.field=BrandID_s&wt=json&facet.method=fc&fq=DataType_s:Product&fq=WebSections_ms:house&fq=VisibleOnline_ms:7&fq={!tag%3Dcurrent_group}GroupIds_ms:*&rows=20}
>>>> hits=2549 status=0 QTime=1263
>>>>
>>>>
>>>> If I run the same query after the index has registered I see a QTime of
>>>> over a second, the second time I run the query I see around 80ms. This
>>>> leads
>>>> me to believe the warming did not occur or the query was not commited to
>>>> cache on start up of the new searcher.
>>>> Can someone please advise on how to use the newSearcher queries to
>>>> effectively warm SolR caches. Should I see an improved response for the
>>>> first time I run the query if the same query has been used as a
>>>> newSearcher
>>>> query?
>>>> Cheers,
>>>> Dalton
>>>
>>>
>>
>>
>
>
Re: newSearcher autowarming queries in solrconfig.xml run but does
not appear to warm cache
Posted by Dalton Gooding <da...@yahoo.com.au.INVALID>.
Erick,
I think you might have nailed it.
After the three warming queries, I get the below when registering a new searcher. How can I find out what I am missing in my warming queries?
Registered new searcher Searcher@15cdc368[core1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a3p4(5.3.1):C313761/57815:delGen=1722) Uninverting(_a7bs(5.3.1):c22601/8393:delGen=464) Uninverting(_a7np(5.3.1):C37794/13471:delGen=244) Uninverting(_a7rp(5.3.1):c2490/760:delGen=77) Uninverting(_a7u7(5.3.1):c5968/338:delGen=27) Uninverting(_a7rz(5.3.1):c4306/1718:delGen=94) Uninverting(_a806(5.3.1):c1734/7:delGen=6) Uninverting(_a7tx(5.3.1):c1900/67:delGen=10) Uninverting(_a7tn(5.3.1):c1900/24:delGen=9) Uninverting(_a7yt(5.3.1):c2643/144:delGen=8) Uninverting(_a7zn(5.3.1):c1595/2:delGen=2) Uninverting(_a82v(5.3.1):c31) Uninverting(_a843(5.3.1):c23/3:delGen=1) Uninverting(_a844(5.3.1):C3/1:delGen=1) Uninverting(_a846(5.3.1):C1) Uninverting(_a848(5.3.1):C5/1:delGen=1) Uninverting(_a84a(5.3.1):C1) Uninverting(_a84c(5.3.1):C1)))}
On Friday, 14 October 2016, 9:50, Erick Erickson <er...@gmail.com> wrote:
Well, that's a puzzle, sorry I don't have a good answer.
The fact that your newSearcher event to be fired _should_ populate
the low-level caches. BTW, what's your autowarm count on filterCache and
queryResultCache? Have you tried setting them to non-zero values? Those
won't help when you first start Solr, but that should be rare.
Do note that your newSearcher events should mention a series of different values
from the fields in question.
Actually here's what I'd do. Look carefully in your Solr log after you
do a commit and
particularly when you fire your first query after the new searcher is
opened. Do you see
any suspicious messages like "Uninverting field" or the like? That
would indicate sorting
or faceting on a field that wasn't warmed by the newSearcher because
you didn't mention
sorting or faceting or whatever in your warming query.
Can we see the newSearcher entry and the query you say is "similar"
but slow. My _guess_
is that some innocent-seeming difference between the two is the issue.
Best,
Erick
On Sun, Oct 9, 2016 at 7:08 PM, Dalton Gooding
<da...@yahoo.com.au> wrote:
> Erick,
>
> I have tried tuning the queries with some limited success. I still get
> drastic differences between the first time I fire my warming query (after
> newSearcher ran query) and the second time, or any variant of the query i.e.
> removing fields or changing parameters, it runs much faster.
>
> I am not sure what I am missing here, I put a query into the newSearcher
> section that runs fine, but the exact same query run after warming still
> takes the full time of a un-warmed query.
>
> Can you break it down to the most basic type of newSearcher query to try and
> shrink the gap between first query and subsequent queries sent?
>
> I cannot see why sending the same query after a newSearcher is slow, when
> subsequent queries run faster. I figured this was the idea of the
> newSearcher stanza's.
>
>
> On Friday, 7 October 2016, 14:45, Erick Erickson <er...@gmail.com>
> wrote:
>
>
> Replying on the public thread, somehow your mail was sent to me privately.
>
> Pasted your email to me below for others.
>
> You are still confusing documents and results. Forget about the rows
> parameter, for this discussion it's irrelevant.
>
> The QTime is the time spent searching. It is unaffected by whether a
> document is in the documentCache or not.
> It _solely_ measures the time that Solr/Lucene take to find the top N
> documents (where N is the rows param) and
> record their internal Lucene doc ID.
>
> Increasing the rows or the document cache won't change anything about
> the QTime. The documentCache is
> totally the wrong place to focus.
>
>
> The response when you re-submit the query suggests that getting the
> top N docs' internal Lucene ID is
> fetched from the queryResultCache. Changing the window size is also
> irrelevant to this discussion. If you
> vary the query even slightly you won't hit the queryResultCache. A
> very easy way to check this is the
> admin UI>>select core>>plugins/stats>>QueryHandler and then probably
> the "select" handler. If you see
> the hits go up after the fast query then you're getting the results
> from the querResultCache.
>
> What _is_ relevant is populating the low-level Lucene caches with
> values from the indexed terms. My
> contention is that this is not happening with match-all queries, i.e.
> field:* or field:[* TO *] because in
> those cases, a doc matches or doesn't based on whether it has anything
> in the field. There's no point
> in finding values since it doesn't matter anyway. And "finding values"
> means reading indexed terms
> from disk into low-level Lucene caches.
>
> When I say "populate the low-level Lucene caches", what I'm really
> talking about is reading them from
> disk into your physical memory via MMapDirectory, see Uwe's excellent blog:
> http://blog.thetaphi.de/2012/07/use-lucenes-mmapdirectory-on-64bit.html
>
> So the suggestion is that you use real values from your index or
> possibly ranges is so that part or all
> of your disk files get read into MMapDirectorySpace via the first or
> new Searcher event.
>
> Please just give it a try. My bet is that you'll see your QTime values
> first time after autowarming
> go down. Significantly. Be sure to use a wide variety of different
> values for autowarming.
>
> BTW, the autowarmCounts in solrconfig.xml filterCache and
> queryResultCache are intended
> to warm by using the last N fq or q clauses on the theory that the
> most recent N are predictive
> of the next N.
>
> Best,
> Erick
>
>
> ***************
>
> I believe the return time back to the command line from the curl
> command and the QTime as shown below
>
> time curl -v
> 'http://<SolR>/solr/core1/select?fq=DataType_s%3AProduct&fq=WebSections_ms%3Ahouse&fq=%28VisibleOnline_ms%3ANAT+OR+VisibleOnline_ms%3A7%29&fq=%7B%21tag%3Dcurrent_group%7DGroupIds_ms%3A458&sort=SalesRank_f+desc&facet=true&facet.field=%7B%21ex%3Dcurrent_group%7Dattr_GroupLevel0&facet.field=BrandID_s&facet.field=%7B%21ex%3Dcurrent_group%7Dattr_GroupLevel2&facet.field=%7B%21ex%3Dcurrent_group%7Dattr_GroupLevel1&facet.field=SubBrandID_s&facet.field=ProductAttr_967_ms&facet.field=ProductAttr_NEG21_ms&facet.field=ProductAttr_1852_ms&facet.query=Price_7_f%3A%5B%2A+TO+%2A%5D&facet.query=Price_2_f%3A%5B%2A+TO+%2A%5D&facet.query=Price_3_f%3A%5B%2A+TO+%2A%5D&facet.query=Price_4_f%3A%5B%2A+TO+%2A%5D&facet.query=Price_5_f%3A%5B%2A+TO+%2A%5D&facet.query=Price_6_f%3A%5B%2A+TO+%2A%5D&facet.mincount=1&wt=json&json.nl=map&q=%28title%3A%2A+OR+text%3A%2A%29+AND+%28ms%3ALive%29&start=0&rows=24'
>
> real 0m1.436s
> user 0m0.001s
> sys 0m0.006s
>
> "QTime":1387
>
> From what you suggested, changing the rows value from 20 to something
> greater should add more documents to the cache. Injunction with tuning
> the queries to remove the * wild card, this should provide a better
> warming query?
>
> Should I also increase the queryResultWindowSize in the solrconfig.xml
> to help built out the cache?
>
> Cheers,
>
> Guy
>
>
>
>
>
> On Thu, Oct 6, 2016 at 4:43 PM, Dalton Gooding
> <da...@yahoo.com.au> wrote:
>> Erick,
>>
>> Thanks for the response. After I run the initial query and get a long
>> response time, if I change the query to remove or add additional query
>> statements, I find the speed is good.
>>
>> If I run the modified query after a new searcher has registered, the
>> response is slow but after the modified query has been completed, the
>> warming query sent from CuRl is much faster. I assume it is because the
>> document cache has updated with the documents from the modified query. A
>> large number of our queries work with the same document set, I am trying
>> to
>> get a warming query to populate the document cache to be as big as
>> feasible.
>>
>> Should the firstSearcher and newSearcher warm the document cache?
>>
>>
>> On Friday, 7 October 2016, 9:31, Erick Erickson <er...@gmail.com>
>> wrote:
>>
>>
>> Submitting the exact same query twice will return results from the
>> queryResultCache. I'm not entirely
>> sure that the firstSearcher events get put into the cache.
>>
>> So if you change the query even slighty my guess is that you'll see
>> response times very close to your
>> original ones of over a second.
>>
>> Best,
>> Erick
>>
>> On Thu, Oct 6, 2016 at 2:56 PM, Dalton Gooding
>> <da...@yahoo.com.au.invalid> wrote:
>>> After setting a number of newSearcher and firstSearcher queries, I can
>>> see
>>> in the console logs that the queries are run, but when I run the same
>>> query
>>> against the new searcher (using CuRL), I get a slow response time for the
>>> first run.
>>>
>>> Config:
>>> <listener event="newSearcher" class="solr.QuerySenderListener">
>>> <arr name="queries"> <lst> <str name="fq">DataType_s:Product</str>
>>> <str name="fq">WebSections_ms:house</str> <str
>>> name="fq">{!tag=current_group}GroupIds_ms:*</str>
>>> <str name="facet">true</str> <str
>>> name="facet.field">BrandID_s</str> <str
>>> name="facet.query">Price_2_f:[* TO *]</str> <str
>>> name="facet.query">Price_3_f:[* TO *]</str> <str
>>> name="facet.query">Price_4_f:[* TO *]</str> <str
>>> name="facet.query">Price_5_f:[* TO *]</str> <str
>>> name="facet.query">Price_6_f:[* TO *]</str> <str
>>> name="facet.query">Price_7_f:[* TO *]</str> <str
>>> name="facet.query">Price_8_f:[* TO *]</str> <str
>>> name="facet.mincount">1</str> <str
>>> name="facet.method">fc</str>
>>> <str name="wt">json</str> <str name="json.nl">map</str>
>>> <str name="q">(title:* OR text:*)</str> <str
>>> name="start">0</str> <str name="rows">20</str> </lst>
>>> </arr> </listener>
>>>
>>> Console log:
>>> INFO (searcherExecutor-7-thread-1-processing-x:core1) [ x:core1]
>>> o.a.s.c.S.Request [core1] webapp=null path=null
>>>
>>> params={facet=true&facet.mincount=1&start=0&facet.query=Price_2_f:[*+TO+*]&facet.query=Price_3_f:[*+TO+*]&facet.query=Price_4_f:[*+TO+*]&facet.query=Price_5_f:[*+TO+*]&facet.query=Price_6_f:[*+TO+*]&facet.query=Price_7_f:[*+TO+*]&facet.query=Price_8_f:[*+TO+*]&event=newSearcher&q=(title:*+OR+text:*)&distrib=false&json.nl=map&facet.field=BrandID_s&wt=json&facet.method=fc&fq=DataType_s:Product&fq=WebSections_ms:house&fq=VisibleOnline_ms:7&fq={!tag%3Dcurrent_group}GroupIds_ms:*&rows=20}
>>> hits=2549 status=0 QTime=1263
>>>
>>>
>>> If I run the same query after the index has registered I see a QTime of
>>> over a second, the second time I run the query I see around 80ms. This
>>> leads
>>> me to believe the warming did not occur or the query was not commited to
>>> cache on start up of the new searcher.
>>> Can someone please advise on how to use the newSearcher queries to
>>> effectively warm SolR caches. Should I see an improved response for the
>>> first time I run the query if the same query has been used as a
>>> newSearcher
>>> query?
>>> Cheers,
>>> Dalton
>>
>>
>
> On Thu, Oct 6, 2016 at 4:43 PM, Dalton Gooding
> <da...@yahoo.com.au> wrote:
>> Erick,
>>
>> Thanks for the response. After I run the initial query and get a long
>> response time, if I change the query to remove or add additional query
>> statements, I find the speed is good.
>>
>> If I run the modified query after a new searcher has registered, the
>> response is slow but after the modified query has been completed, the
>> warming query sent from CuRl is much faster. I assume it is because the
>> document cache has updated with the documents from the modified query. A
>> large number of our queries work with the same document set, I am trying
>> to
>> get a warming query to populate the document cache to be as big as
>> feasible.
>>
>> Should the firstSearcher and newSearcher warm the document cache?
>>
>>
>> On Friday, 7 October 2016, 9:31, Erick Erickson <er...@gmail.com>
>> wrote:
>>
>>
>> Submitting the exact same query twice will return results from the
>> queryResultCache. I'm not entirely
>> sure that the firstSearcher events get put into the cache.
>>
>> So if you change the query even slighty my guess is that you'll see
>> response times very close to your
>> original ones of over a second.
>>
>> Best,
>> Erick
>>
>>
>> On Thu, Oct 6, 2016 at 2:56 PM, Dalton Gooding
>> <da...@yahoo.com.au.invalid> wrote:
>>> After setting a number of newSearcher and firstSearcher queries, I can
>>> see
>>> in the console logs that the queries are run, but when I run the same
>>> query
>>> against the new searcher (using CuRL), I get a slow response time for the
>>> first run.
>>>
>>> Config:
>>> <listener event="newSearcher" class="solr.QuerySenderListener">
>>> <arr name="queries"> <lst> <str name="fq">DataType_s:Product</str>
>>> <str name="fq">WebSections_ms:house</str> <str
>>> name="fq">{!tag=current_group}GroupIds_ms:*</str>
>>> <str name="facet">true</str> <str
>>> name="facet.field">BrandID_s</str> <str
>>> name="facet.query">Price_2_f:[* TO *]</str> <str
>>> name="facet.query">Price_3_f:[* TO *]</str> <str
>>> name="facet.query">Price_4_f:[* TO *]</str> <str
>>> name="facet.query">Price_5_f:[* TO *]</str> <str
>>> name="facet.query">Price_6_f:[* TO *]</str> <str
>>> name="facet.query">Price_7_f:[* TO *]</str> <str
>>> name="facet.query">Price_8_f:[* TO *]</str> <str
>>> name="facet.mincount">1</str> <str
>>> name="facet.method">fc</str>
>>> <str name="wt">json</str> <str name="json.nl">map</str>
>>> <str name="q">(title:* OR text:*)</str> <str
>>> name="start">0</str> <str name="rows">20</str> </lst>
>>> </arr> </listener>
>>>
>>> Console log:
>>> INFO (searcherExecutor-7-thread-1-processing-x:core1) [ x:core1]
>>> o.a.s.c.S.Request [core1] webapp=null path=null
>>>
>>> params={facet=true&facet.mincount=1&start=0&facet.query=Price_2_f:[*+TO+*]&facet.query=Price_3_f:[*+TO+*]&facet.query=Price_4_f:[*+TO+*]&facet.query=Price_5_f:[*+TO+*]&facet.query=Price_6_f:[*+TO+*]&facet.query=Price_7_f:[*+TO+*]&facet.query=Price_8_f:[*+TO+*]&event=newSearcher&q=(title:*+OR+text:*)&distrib=false&json.nl=map&facet.field=BrandID_s&wt=json&facet.method=fc&fq=DataType_s:Product&fq=WebSections_ms:house&fq=VisibleOnline_ms:7&fq={!tag%3Dcurrent_group}GroupIds_ms:*&rows=20}
>>> hits=2549 status=0 QTime=1263
>>>
>>>
>>> If I run the same query after the index has registered I see a QTime of
>>> over a second, the second time I run the query I see around 80ms. This
>>> leads
>>> me to believe the warming did not occur or the query was not commited to
>>> cache on start up of the new searcher.
>>> Can someone please advise on how to use the newSearcher queries to
>>> effectively warm SolR caches. Should I see an improved response for the
>>> first time I run the query if the same query has been used as a
>>> newSearcher
>>> query?
>>> Cheers,
>>> Dalton
>>
>>
>
>
Re: newSearcher autowarming queries in solrconfig.xml run but does
not appear to warm cache
Posted by Dalton Gooding <da...@yahoo.com.au.INVALID>.
Erick,
I have tried tuning the queries with some limited success. I still get drastic differences between the first time I fire my warming query (after newSearcher ran query) and the second time, or any variant of the query i.e. removing fields or changing parameters, it runs much faster.
I am not sure what I am missing here, I put a query into the newSearcher section that runs fine, but the exact same query run after warming still takes the full time of a un-warmed query.
Can you break it down to the most basic type of newSearcher query to try and shrink the gap between first query and subsequent queries sent?
I cannot see why sending the same query after a newSearcher is slow, when subsequent queries run faster. I figured this was the idea of the newSearcher stanza's.
On Friday, 7 October 2016, 14:45, Erick Erickson <er...@gmail.com> wrote:
Replying on the public thread, somehow your mail was sent to me privately.
Pasted your email to me below for others.
You are still confusing documents and results. Forget about the rows
parameter, for this discussion it's irrelevant.
The QTime is the time spent searching. It is unaffected by whether a
document is in the documentCache or not.
It _solely_ measures the time that Solr/Lucene take to find the top N
documents (where N is the rows param) and
record their internal Lucene doc ID.
Increasing the rows or the document cache won't change anything about
the QTime. The documentCache is
totally the wrong place to focus.
The response when you re-submit the query suggests that getting the
top N docs' internal Lucene ID is
fetched from the queryResultCache. Changing the window size is also
irrelevant to this discussion. If you
vary the query even slightly you won't hit the queryResultCache. A
very easy way to check this is the
admin UI>>select core>>plugins/stats>>QueryHandler and then probably
the "select" handler. If you see
the hits go up after the fast query then you're getting the results
from the querResultCache.
What _is_ relevant is populating the low-level Lucene caches with
values from the indexed terms. My
contention is that this is not happening with match-all queries, i.e.
field:* or field:[* TO *] because in
those cases, a doc matches or doesn't based on whether it has anything
in the field. There's no point
in finding values since it doesn't matter anyway. And "finding values"
means reading indexed terms
from disk into low-level Lucene caches.
When I say "populate the low-level Lucene caches", what I'm really
talking about is reading them from
disk into your physical memory via MMapDirectory, see Uwe's excellent blog:
http://blog.thetaphi.de/2012/07/use-lucenes-mmapdirectory-on-64bit.html
So the suggestion is that you use real values from your index or
possibly ranges is so that part or all
of your disk files get read into MMapDirectorySpace via the first or
new Searcher event.
Please just give it a try. My bet is that you'll see your QTime values
first time after autowarming
go down. Significantly. Be sure to use a wide variety of different
values for autowarming.
BTW, the autowarmCounts in solrconfig.xml filterCache and
queryResultCache are intended
to warm by using the last N fq or q clauses on the theory that the
most recent N are predictive
of the next N.
Best,
Erick
***************
I believe the return time back to the command line from the curl
command and the QTime as shown below
time curl -v 'http://<SolR>/solr/core1/select?fq=DataType_s%3AProduct&fq=WebSections_ms%3Ahouse&fq=%28VisibleOnline_ms%3ANAT+OR+VisibleOnline_ms%3A7%29&fq=%7B%21tag%3Dcurrent_group%7DGroupIds_ms%3A458&sort=SalesRank_f+desc&facet=true&facet.field=%7B%21ex%3Dcurrent_group%7Dattr_GroupLevel0&facet.field=BrandID_s&facet.field=%7B%21ex%3Dcurrent_group%7Dattr_GroupLevel2&facet.field=%7B%21ex%3Dcurrent_group%7Dattr_GroupLevel1&facet.field=SubBrandID_s&facet.field=ProductAttr_967_ms&facet.field=ProductAttr_NEG21_ms&facet.field=ProductAttr_1852_ms&facet.query=Price_7_f%3A%5B%2A+TO+%2A%5D&facet.query=Price_2_f%3A%5B%2A+TO+%2A%5D&facet.query=Price_3_f%3A%5B%2A+TO+%2A%5D&facet.query=Price_4_f%3A%5B%2A+TO+%2A%5D&facet.query=Price_5_f%3A%5B%2A+TO+%2A%5D&facet.query=Price_6_f%3A%5B%2A+TO+%2A%5D&facet.mincount=1&wt=json&json.nl=map&q=%28title%3A%2A+OR+text%3A%2A%29+AND+%28ms%3ALive%29&start=0&rows=24'
real 0m1.436s
user 0m0.001s
sys 0m0.006s
"QTime":1387
From what you suggested, changing the rows value from 20 to something
greater should add more documents to the cache. Injunction with tuning
the queries to remove the * wild card, this should provide a better
warming query?
Should I also increase the queryResultWindowSize in the solrconfig.xml
to help built out the cache?
Cheers,
Guy
On Thu, Oct 6, 2016 at 4:43 PM, Dalton Gooding
<da...@yahoo.com.au> wrote:
> Erick,
>
> Thanks for the response. After I run the initial query and get a long
> response time, if I change the query to remove or add additional query
> statements, I find the speed is good.
>
> If I run the modified query after a new searcher has registered, the
> response is slow but after the modified query has been completed, the
> warming query sent from CuRl is much faster. I assume it is because the
> document cache has updated with the documents from the modified query. A
> large number of our queries work with the same document set, I am trying to
> get a warming query to populate the document cache to be as big as feasible.
>
> Should the firstSearcher and newSearcher warm the document cache?
>
>
> On Friday, 7 October 2016, 9:31, Erick Erickson <er...@gmail.com>
> wrote:
>
>
> Submitting the exact same query twice will return results from the
> queryResultCache. I'm not entirely
> sure that the firstSearcher events get put into the cache.
>
> So if you change the query even slighty my guess is that you'll see
> response times very close to your
> original ones of over a second.
>
> Best,
> Erick
>
> On Thu, Oct 6, 2016 at 2:56 PM, Dalton Gooding
> <da...@yahoo.com.au.invalid> wrote:
>> After setting a number of newSearcher and firstSearcher queries, I can see
>> in the console logs that the queries are run, but when I run the same query
>> against the new searcher (using CuRL), I get a slow response time for the
>> first run.
>>
>> Config:
>> <listener event="newSearcher" class="solr.QuerySenderListener">
>> <arr name="queries"> <lst> <str name="fq">DataType_s:Product</str>
>> <str name="fq">WebSections_ms:house</str> <str
>> name="fq">{!tag=current_group}GroupIds_ms:*</str>
>> <str name="facet">true</str> <str
>> name="facet.field">BrandID_s</str> <str
>> name="facet.query">Price_2_f:[* TO *]</str> <str
>> name="facet.query">Price_3_f:[* TO *]</str> <str
>> name="facet.query">Price_4_f:[* TO *]</str> <str
>> name="facet.query">Price_5_f:[* TO *]</str> <str
>> name="facet.query">Price_6_f:[* TO *]</str> <str
>> name="facet.query">Price_7_f:[* TO *]</str> <str
>> name="facet.query">Price_8_f:[* TO *]</str> <str
>> name="facet.mincount">1</str> <str name="facet.method">fc</str>
>> <str name="wt">json</str> <str name="json.nl">map</str>
>> <str name="q">(title:* OR text:*)</str> <str
>> name="start">0</str> <str name="rows">20</str> </lst>
>> </arr> </listener>
>>
>> Console log:
>> INFO (searcherExecutor-7-thread-1-processing-x:core1) [ x:core1]
>> o.a.s.c.S.Request [core1] webapp=null path=null
>> params={facet=true&facet.mincount=1&start=0&facet.query=Price_2_f:[*+TO+*]&facet.query=Price_3_f:[*+TO+*]&facet.query=Price_4_f:[*+TO+*]&facet.query=Price_5_f:[*+TO+*]&facet.query=Price_6_f:[*+TO+*]&facet.query=Price_7_f:[*+TO+*]&facet.query=Price_8_f:[*+TO+*]&event=newSearcher&q=(title:*+OR+text:*)&distrib=false&json.nl=map&facet.field=BrandID_s&wt=json&facet.method=fc&fq=DataType_s:Product&fq=WebSections_ms:house&fq=VisibleOnline_ms:7&fq={!tag%3Dcurrent_group}GroupIds_ms:*&rows=20}
>> hits=2549 status=0 QTime=1263
>>
>>
>> If I run the same query after the index has registered I see a QTime of
>> over a second, the second time I run the query I see around 80ms. This leads
>> me to believe the warming did not occur or the query was not commited to
>> cache on start up of the new searcher.
>> Can someone please advise on how to use the newSearcher queries to
>> effectively warm SolR caches. Should I see an improved response for the
>> first time I run the query if the same query has been used as a newSearcher
>> query?
>> Cheers,
>> Dalton
>
>
On Thu, Oct 6, 2016 at 4:43 PM, Dalton Gooding
<da...@yahoo.com.au> wrote:
> Erick,
>
> Thanks for the response. After I run the initial query and get a long
> response time, if I change the query to remove or add additional query
> statements, I find the speed is good.
>
> If I run the modified query after a new searcher has registered, the
> response is slow but after the modified query has been completed, the
> warming query sent from CuRl is much faster. I assume it is because the
> document cache has updated with the documents from the modified query. A
> large number of our queries work with the same document set, I am trying to
> get a warming query to populate the document cache to be as big as feasible.
>
> Should the firstSearcher and newSearcher warm the document cache?
>
>
> On Friday, 7 October 2016, 9:31, Erick Erickson <er...@gmail.com>
> wrote:
>
>
> Submitting the exact same query twice will return results from the
> queryResultCache. I'm not entirely
> sure that the firstSearcher events get put into the cache.
>
> So if you change the query even slighty my guess is that you'll see
> response times very close to your
> original ones of over a second.
>
> Best,
> Erick
>
>
> On Thu, Oct 6, 2016 at 2:56 PM, Dalton Gooding
> <da...@yahoo.com.au.invalid> wrote:
>> After setting a number of newSearcher and firstSearcher queries, I can see
>> in the console logs that the queries are run, but when I run the same query
>> against the new searcher (using CuRL), I get a slow response time for the
>> first run.
>>
>> Config:
>> <listener event="newSearcher" class="solr.QuerySenderListener">
>> <arr name="queries"> <lst> <str name="fq">DataType_s:Product</str>
>> <str name="fq">WebSections_ms:house</str> <str
>> name="fq">{!tag=current_group}GroupIds_ms:*</str>
>> <str name="facet">true</str> <str
>> name="facet.field">BrandID_s</str> <str
>> name="facet.query">Price_2_f:[* TO *]</str> <str
>> name="facet.query">Price_3_f:[* TO *]</str> <str
>> name="facet.query">Price_4_f:[* TO *]</str> <str
>> name="facet.query">Price_5_f:[* TO *]</str> <str
>> name="facet.query">Price_6_f:[* TO *]</str> <str
>> name="facet.query">Price_7_f:[* TO *]</str> <str
>> name="facet.query">Price_8_f:[* TO *]</str> <str
>> name="facet.mincount">1</str> <str name="facet.method">fc</str>
>> <str name="wt">json</str> <str name="json.nl">map</str>
>> <str name="q">(title:* OR text:*)</str> <str
>> name="start">0</str> <str name="rows">20</str> </lst>
>> </arr> </listener>
>>
>> Console log:
>> INFO (searcherExecutor-7-thread-1-processing-x:core1) [ x:core1]
>> o.a.s.c.S.Request [core1] webapp=null path=null
>> params={facet=true&facet.mincount=1&start=0&facet.query=Price_2_f:[*+TO+*]&facet.query=Price_3_f:[*+TO+*]&facet.query=Price_4_f:[*+TO+*]&facet.query=Price_5_f:[*+TO+*]&facet.query=Price_6_f:[*+TO+*]&facet.query=Price_7_f:[*+TO+*]&facet.query=Price_8_f:[*+TO+*]&event=newSearcher&q=(title:*+OR+text:*)&distrib=false&json.nl=map&facet.field=BrandID_s&wt=json&facet.method=fc&fq=DataType_s:Product&fq=WebSections_ms:house&fq=VisibleOnline_ms:7&fq={!tag%3Dcurrent_group}GroupIds_ms:*&rows=20}
>> hits=2549 status=0 QTime=1263
>>
>>
>> If I run the same query after the index has registered I see a QTime of
>> over a second, the second time I run the query I see around 80ms. This leads
>> me to believe the warming did not occur or the query was not commited to
>> cache on start up of the new searcher.
>> Can someone please advise on how to use the newSearcher queries to
>> effectively warm SolR caches. Should I see an improved response for the
>> first time I run the query if the same query has been used as a newSearcher
>> query?
>> Cheers,
>> Dalton
>
>
Re: newSearcher autowarming queries in solrconfig.xml run but does
not appear to warm cache
Posted by Dalton Gooding <da...@yahoo.com.au.INVALID>.
Erick,
Thanks for the response. After I run the initial query and get a long response time, if I change the query to remove or add additional query statements, I find the speed is good.
If I run the modified query after a new searcher has registered, the response is slow but after the modified query has been completed, the warming query sent from CuRl is much faster. I assume it is because the document cache has updated with the documents from the modified query. A large number of our queries work with the same document set, I am trying to get a warming query to populate the document cache to be as big as feasible.
Should the firstSearcher and newSearcher warm the document cache?
On Friday, 7 October 2016, 9:31, Erick Erickson <er...@gmail.com> wrote:
Submitting the exact same query twice will return results from the
queryResultCache. I'm not entirely
sure that the firstSearcher events get put into the cache.
So if you change the query even slighty my guess is that you'll see
response times very close to your
original ones of over a second.
Best,
Erick
On Thu, Oct 6, 2016 at 2:56 PM, Dalton Gooding
<da...@yahoo.com.au.invalid> wrote:
> After setting a number of newSearcher and firstSearcher queries, I can see in the console logs that the queries are run, but when I run the same query against the new searcher (using CuRL), I get a slow response time for the first run.
>
> Config:
> <listener event="newSearcher" class="solr.QuerySenderListener"> <arr name="queries"> <lst> <str name="fq">DataType_s:Product</str> <str name="fq">WebSections_ms:house</str> <str name="fq">{!tag=current_group}GroupIds_ms:*</str>
> <str name="facet">true</str> <str name="facet.field">BrandID_s</str> <str name="facet.query">Price_2_f:[* TO *]</str> <str name="facet.query">Price_3_f:[* TO *]</str> <str name="facet.query">Price_4_f:[* TO *]</str> <str name="facet.query">Price_5_f:[* TO *]</str> <str name="facet.query">Price_6_f:[* TO *]</str> <str name="facet.query">Price_7_f:[* TO *]</str> <str name="facet.query">Price_8_f:[* TO *]</str> <str name="facet.mincount">1</str> <str name="facet.method">fc</str> <str name="wt">json</str> <str name="json.nl">map</str> <str name="q">(title:* OR text:*)</str> <str name="start">0</str> <str name="rows">20</str> </lst> </arr> </listener>
>
> Console log:
> INFO (searcherExecutor-7-thread-1-processing-x:core1) [ x:core1] o.a.s.c.S.Request [core1] webapp=null path=null params={facet=true&facet.mincount=1&start=0&facet.query=Price_2_f:[*+TO+*]&facet.query=Price_3_f:[*+TO+*]&facet.query=Price_4_f:[*+TO+*]&facet.query=Price_5_f:[*+TO+*]&facet.query=Price_6_f:[*+TO+*]&facet.query=Price_7_f:[*+TO+*]&facet.query=Price_8_f:[*+TO+*]&event=newSearcher&q=(title:*+OR+text:*)&distrib=false&json.nl=map&facet.field=BrandID_s&wt=json&facet.method=fc&fq=DataType_s:Product&fq=WebSections_ms:house&fq=VisibleOnline_ms:7&fq={!tag%3Dcurrent_group}GroupIds_ms:*&rows=20} hits=2549 status=0 QTime=1263
>
>
> If I run the same query after the index has registered I see a QTime of over a second, the second time I run the query I see around 80ms. This leads me to believe the warming did not occur or the query was not commited to cache on start up of the new searcher.
> Can someone please advise on how to use the newSearcher queries to effectively warm SolR caches. Should I see an improved response for the first time I run the query if the same query has been used as a newSearcher query?
> Cheers,
> Dalton
Re: newSearcher autowarming queries in solrconfig.xml run but does
not appear to warm cache
Posted by Erick Erickson <er...@gmail.com>.
Submitting the exact same query twice will return results from the
queryResultCache. I'm not entirely
sure that the firstSearcher events get put into the cache.
So if you change the query even slighty my guess is that you'll see
response times very close to your
original ones of over a second.
Best,
Erick
On Thu, Oct 6, 2016 at 2:56 PM, Dalton Gooding
<da...@yahoo.com.au.invalid> wrote:
> After setting a number of newSearcher and firstSearcher queries, I can see in the console logs that the queries are run, but when I run the same query against the new searcher (using CuRL), I get a slow response time for the first run.
>
> Config:
> <listener event="newSearcher" class="solr.QuerySenderListener"> <arr name="queries"> <lst> <str name="fq">DataType_s:Product</str> <str name="fq">WebSections_ms:house</str> <str name="fq">{!tag=current_group}GroupIds_ms:*</str>
> <str name="facet">true</str> <str name="facet.field">BrandID_s</str> <str name="facet.query">Price_2_f:[* TO *]</str> <str name="facet.query">Price_3_f:[* TO *]</str> <str name="facet.query">Price_4_f:[* TO *]</str> <str name="facet.query">Price_5_f:[* TO *]</str> <str name="facet.query">Price_6_f:[* TO *]</str> <str name="facet.query">Price_7_f:[* TO *]</str> <str name="facet.query">Price_8_f:[* TO *]</str> <str name="facet.mincount">1</str> <str name="facet.method">fc</str> <str name="wt">json</str> <str name="json.nl">map</str> <str name="q">(title:* OR text:*)</str> <str name="start">0</str> <str name="rows">20</str> </lst> </arr> </listener>
>
> Console log:
> INFO (searcherExecutor-7-thread-1-processing-x:core1) [ x:core1] o.a.s.c.S.Request [core1] webapp=null path=null params={facet=true&facet.mincount=1&start=0&facet.query=Price_2_f:[*+TO+*]&facet.query=Price_3_f:[*+TO+*]&facet.query=Price_4_f:[*+TO+*]&facet.query=Price_5_f:[*+TO+*]&facet.query=Price_6_f:[*+TO+*]&facet.query=Price_7_f:[*+TO+*]&facet.query=Price_8_f:[*+TO+*]&event=newSearcher&q=(title:*+OR+text:*)&distrib=false&json.nl=map&facet.field=BrandID_s&wt=json&facet.method=fc&fq=DataType_s:Product&fq=WebSections_ms:house&fq=VisibleOnline_ms:7&fq={!tag%3Dcurrent_group}GroupIds_ms:*&rows=20} hits=2549 status=0 QTime=1263
>
>
> If I run the same query after the index has registered I see a QTime of over a second, the second time I run the query I see around 80ms. This leads me to believe the warming did not occur or the query was not commited to cache on start up of the new searcher.
> Can someone please advise on how to use the newSearcher queries to effectively warm SolR caches. Should I see an improved response for the first time I run the query if the same query has been used as a newSearcher query?
> Cheers,
> Dalton