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 zhenyuan wei <ti...@gmail.com> on 2018/09/03 11:45:46 UTC
How long does a query?q=field1:2312 should cost? exactly hit one document.
Hi ，
I am curious “How long does a query q=field1:2312 cost , which
exactly match only one document? ”， Of course we just discuss no
queryResultCache with match in this situation.
In fact my QTime is 150ms+， it is too long.
Re: How long does a query?q=field1:2312 should cost? exactly hit one document.
Posted by zhenyuan wei <ti...@gmail.com>.
Only a termQuery q=field1:2312, No other conditions.
I try debug now, but can not find out what is the main cost.
Debug=timing output like :
{
"responseHeader":{
"zkConnected":true,
"status":0,
"QTime":157,
"params":{
"q":"v00_s:15de21c670ae7c3f6f3f1f37029303c9",
"debug":"timing"}},
"response":{"numFound":1,"start":0,"maxScore":17.099754,"docs":[
{
"v00_s":"15de21c670ae7c3f6f3f1f37029303c9",
"v01_s":"7596295605015",
"v02_s":"Mp9XkmrRXhFChgMAGoydOvAD",
"v03_l":555,
"v04_s":"55",
"v05_s":"39994237071313698949",
"v06_s":"3",
"v07_s":"155",
"v08_s":"5",
"v09_s":"15",
"v10_s":"15",
"v11_s":"555",
"v12_s":"43819292",
"v13_s":"549754428",
"v14_s":"8111596961",
"id":"00000000000000000000000555",
"_version_":1610106981630083079}]
},
"debug":{
"timing":{
"time":6336.0,
"prepare":{
"time":8.0,
"query":{
"time":8.0},
"facet":{
"time":0.0},
"facet_module":{
"time":0.0},
"mlt":{
"time":0.0},
"highlight":{
"time":0.0},
"stats":{
"time":0.0},
"expand":{
"time":0.0},
"terms":{
"time":0.0},
"debug":{
"time":0.0}},
"process":{
"time":6270.0,
"query":{
"time":6268.0,
"doProcessSearchByIds":{
"time":0.0},
"doProcessUngroupedSearch":{
"time":6265.0,
"search":{
"time":6261.0,
"getDocListC":{
"time":6261.0,
"lookup_queryResultCache":{
"time":0.0},
"lookupNotuseFilterCacheTimer":{
"time":6258.0},
"getDocListNCTimer":{
"time":6258.0,
"getProcessedFilter":{
"time":0.0},
"buildAndRunCollectorChain2":{
"time":6255.0},
"topDocs":{
"time":0.0}}}},
"doFieldSortValues":{
"time":0.0},
"doPrefetch":{
"time":0.0}}},
"facet":{
"time":0.0},
"facet_module":{
"time":0.0},
"mlt":{
"time":0.0},
"highlight":{
"time":0.0},
"stats":{
"time":0.0},
"expand":{
"time":0.0},
"terms":{
"time":0.0},
"debug":{
"time":0.0}}}}}
My request is : curl "
http://emr-worker-2:8983/solr/collection001/query?q=v00_s:
15de21c670ae7c3f6f3f1f37029303c9&debug=timing"
I also hope to using debug=true to find out more things，so I added some
sub timer to trace which sub method is slowly.
And found , as above, the "SolrIndexSearch.buildAndRunCollectorChain() "
cost a lot。
（ if I want to find out the answer, I think I have not idea but debug
tracing to deeper into lucene level method.)
*At this moment, I have another question too, why debug time is 6336.0,
which less than QTime=157 ? *
Erik Hatcher <er...@gmail.com> 于2018年9月3日周一 下午8:30写道：
> Add debug=true and see where the time goes, in which components?
>
> Highlighting is my culprit guess. Or faceting?
>
> > On Sep 3, 2018, at 07:45, zhenyuan wei <ti...@gmail.com> wrote:
> >
> > Hi ，
> > I am curious “How long does a query q=field1:2312 cost , which
> > exactly match only one document? ”， Of course we just discuss no
> > queryResultCache with match in this situation.
> > In fact my QTime is 150ms+， it is too long.
>
Re: How long does a query?q=field1:2312 should cost? exactly hit one document.
Posted by Erick Erickson <er...@gmail.com>.
My guess is that you're searching un-warmed instances of Solr and are
seeing the time it takes to read the index structures into memory the
first time. What happens if you turn off indexing and query a number
of values (not the same one or you'll hit the queryResultCache).
So your first query would be:
"q":"v00_s:1"
your second
"q":"v00_s:2",
and so on. I'd expect to see decreasing QTimes and after the first few
a pretty steady response time.
Beyond that, what are your machine/index characteristics? How many
docs per replica? What version of Solr? How much heap allocated to the
JVM? How much RAM on the machine? you might review:'
https://wiki.apache.org/solr/UsingMailingLists
Debug adds overhead to the query response time, I suspect that's what
you're seeing although 6 seconds is surprisingly long.
Best,
Erick
On Mon, Sep 3, 2018 at 6:08 AM zhenyuan wei <ti...@gmail.com> wrote:
>
> Only a termQuery q=field1:2312, No other conditions.
> I try debug now, but can not find out what is the main cost.
> Debug=timing output like :
>
> {
> "responseHeader":{
> "zkConnected":true,
> "status":0,
> "QTime":157,
> "params":{
> "q":"v00_s:15de21c670ae7c3f6f3f1f37029303c9",
> "debug":"timing"}},
> "response":{"numFound":1,"start":0,"maxScore":17.099754,"docs":[
> {
> "v00_s":"15de21c670ae7c3f6f3f1f37029303c9",
> "v01_s":"7596295605015",
> "v02_s":"Mp9XkmrRXhFChgMAGoydOvAD",
> "v03_l":555,
> "v04_s":"55",
> "v05_s":"39994237071313698949",
> "v06_s":"3",
> "v07_s":"155",
> "v08_s":"5",
> "v09_s":"15",
> "v10_s":"15",
> "v11_s":"555",
> "v12_s":"43819292",
> "v13_s":"549754428",
> "v14_s":"8111596961",
> "id":"00000000000000000000000555",
> "_version_":1610106981630083079}]
> },
> "debug":{
> "timing":{
> "time":6336.0,
> "prepare":{
> "time":8.0,
> "query":{
> "time":8.0},
> "facet":{
> "time":0.0},
> "facet_module":{
> "time":0.0},
> "mlt":{
> "time":0.0},
> "highlight":{
> "time":0.0},
> "stats":{
> "time":0.0},
> "expand":{
> "time":0.0},
> "terms":{
> "time":0.0},
> "debug":{
> "time":0.0}},
> "process":{
> "time":6270.0,
> "query":{
> "time":6268.0,
> "doProcessSearchByIds":{
> "time":0.0},
> "doProcessUngroupedSearch":{
> "time":6265.0,
> "search":{
> "time":6261.0,
> "getDocListC":{
> "time":6261.0,
> "lookup_queryResultCache":{
> "time":0.0},
> "lookupNotuseFilterCacheTimer":{
> "time":6258.0},
> "getDocListNCTimer":{
> "time":6258.0,
> "getProcessedFilter":{
> "time":0.0},
> "buildAndRunCollectorChain2":{
> "time":6255.0},
> "topDocs":{
> "time":0.0}}}},
> "doFieldSortValues":{
> "time":0.0},
> "doPrefetch":{
> "time":0.0}}},
> "facet":{
> "time":0.0},
> "facet_module":{
> "time":0.0},
> "mlt":{
> "time":0.0},
> "highlight":{
> "time":0.0},
> "stats":{
> "time":0.0},
> "expand":{
> "time":0.0},
> "terms":{
> "time":0.0},
> "debug":{
> "time":0.0}}}}}
>
>
> My request is : curl "
> http://localhost:8983/solr/collection001/query?q=v00_s
> <http://emr-worker-2:8983/solr/collection001/query?q=v00_s>:
> 15de21c670ae7c3f6f3f1f37029303c9&debug=timing"
>
> I also hope to using debug=true to find out more things，so I added some
> sub timer to trace which sub method is slowly.
> And found , as above, the "SolrIndexSearch.buildAndRunCollectorChain() "
> cost a lot。
> （ if I want to find out the answer, I think I have not idea but debug
> tracing to deeper into lucene level method.)
>
> *At this moment, I have another question too, why debug time is 6336.0,
> which less than QTime=157 ?*
>
> Erik Hatcher <er...@gmail.com> 于2018年9月3日周一 下午8:30写道：
>
> > Add debug=true and see where the time goes, in which components?
> >
> > Highlighting is my culprit guess. Or faceting?
> >
> > > On Sep 3, 2018, at 07:45, zhenyuan wei <ti...@gmail.com> wrote:
> > >
> > > Hi ，
> > > I am curious “How long does a query q=field1:2312 cost , which
> > > exactly match only one document? ”， Of course we just discuss no
> > > queryResultCache with match in this situation.
> > > In fact my QTime is 150ms+， it is too long.
> >
Re: How long does a query?q=field1:2312 should cost? exactly hit one document.
Posted by zhenyuan wei <ti...@gmail.com>.
Only a termQuery q=field1:2312, No other conditions.
I try debug now, but can not find out what is the main cost.
Debug=timing output like :
{
"responseHeader":{
"zkConnected":true,
"status":0,
"QTime":157,
"params":{
"q":"v00_s:15de21c670ae7c3f6f3f1f37029303c9",
"debug":"timing"}},
"response":{"numFound":1,"start":0,"maxScore":17.099754,"docs":[
{
"v00_s":"15de21c670ae7c3f6f3f1f37029303c9",
"v01_s":"7596295605015",
"v02_s":"Mp9XkmrRXhFChgMAGoydOvAD",
"v03_l":555,
"v04_s":"55",
"v05_s":"39994237071313698949",
"v06_s":"3",
"v07_s":"155",
"v08_s":"5",
"v09_s":"15",
"v10_s":"15",
"v11_s":"555",
"v12_s":"43819292",
"v13_s":"549754428",
"v14_s":"8111596961",
"id":"00000000000000000000000555",
"_version_":1610106981630083079}]
},
"debug":{
"timing":{
"time":6336.0,
"prepare":{
"time":8.0,
"query":{
"time":8.0},
"facet":{
"time":0.0},
"facet_module":{
"time":0.0},
"mlt":{
"time":0.0},
"highlight":{
"time":0.0},
"stats":{
"time":0.0},
"expand":{
"time":0.0},
"terms":{
"time":0.0},
"debug":{
"time":0.0}},
"process":{
"time":6270.0,
"query":{
"time":6268.0,
"doProcessSearchByIds":{
"time":0.0},
"doProcessUngroupedSearch":{
"time":6265.0,
"search":{
"time":6261.0,
"getDocListC":{
"time":6261.0,
"lookup_queryResultCache":{
"time":0.0},
"lookupNotuseFilterCacheTimer":{
"time":6258.0},
"getDocListNCTimer":{
"time":6258.0,
"getProcessedFilter":{
"time":0.0},
"buildAndRunCollectorChain2":{
"time":6255.0},
"topDocs":{
"time":0.0}}}},
"doFieldSortValues":{
"time":0.0},
"doPrefetch":{
"time":0.0}}},
"facet":{
"time":0.0},
"facet_module":{
"time":0.0},
"mlt":{
"time":0.0},
"highlight":{
"time":0.0},
"stats":{
"time":0.0},
"expand":{
"time":0.0},
"terms":{
"time":0.0},
"debug":{
"time":0.0}}}}}
My request is : curl "
http://localhost:8983/solr/collection001/query?q=v00_s
<http://emr-worker-2:8983/solr/collection001/query?q=v00_s>:
15de21c670ae7c3f6f3f1f37029303c9&debug=timing"
I also hope to using debug=true to find out more things，so I added some
sub timer to trace which sub method is slowly.
And found , as above, the "SolrIndexSearch.buildAndRunCollectorChain() "
cost a lot。
（ if I want to find out the answer, I think I have not idea but debug
tracing to deeper into lucene level method.)
*At this moment, I have another question too, why debug time is 6336.0,
which less than QTime=157 ?*
Erik Hatcher <er...@gmail.com> 于2018年9月3日周一 下午8:30写道：
> Add debug=true and see where the time goes, in which components?
>
> Highlighting is my culprit guess. Or faceting?
>
> > On Sep 3, 2018, at 07:45, zhenyuan wei <ti...@gmail.com> wrote:
> >
> > Hi ，
> > I am curious “How long does a query q=field1:2312 cost , which
> > exactly match only one document? ”， Of course we just discuss no
> > queryResultCache with match in this situation.
> > In fact my QTime is 150ms+， it is too long.
>
Re: How long does a query?q=field1:2312 should cost? exactly hit one document.
Posted by Erik Hatcher <er...@gmail.com>.
Add debug=true and see where the time goes, in which components?
Highlighting is my culprit guess. Or faceting?
> On Sep 3, 2018, at 07:45, zhenyuan wei <ti...@gmail.com> wrote:
>
> Hi ，
> I am curious “How long does a query q=field1:2312 cost , which
> exactly match only one document? ”， Of course we just discuss no
> queryResultCache with match in this situation.
> In fact my QTime is 150ms+， it is too long.