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 <tins...@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 <erik.hatc...@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 <tins...@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. > >
