CODEWITHSUNDEEP
c#solr
Domi.Zhang
Domi.Zhang

Reputation: 1705

Response time in client was much longer than QTime in tomcat

I have a solr website with about 500 docs ( 30 fileds defined in schema ), and a c# client on the same machine which would sent http get request to that solr website. These logs were recorded by my c# client:

01-16 23:54:49,301 [107] INFO LogHelper - requst time too long: 1054, solr time: 1003
01-16 23:54:49,847 [63] INFO LogHelper - requst time too long: 1068, solr time: 1021
01-16 23:57:17,813 [108] INFO LogHelper - requst time too long: 1051, solr time: 1027
01-16 23:57:18,313 [111] INFO LogHelper - requst time too long: 1031, solr time: 1007
and so on…

You can see , the query time from solr were so long and every similar (between 1000ms to 1050ms). On the same time, the corresponding logs in tomcat:

2013-1-16 23:54:49 org.apache.solr.core.SolrCore execute
Info: [suit1] webapp=/vanclsearchV2 path=/select/ params={fl=id,typeid,createtime,vprice,sprice,price,totalassesscount,totalsalescount,productcode,productname,stylecode,tag,vpricesku,spricesku,pricesku,userrate,assesscount,lstphotos,mainphotos,salesflag,isduanma,detailsalescount,productplusstyleinfo&sort=createtime+desc&start=0&q=*:*&wt=json&fq=ancestorsid:(28976+OR+28978)&fq=typeid:(1)&rows=30} hits=43 status=0 QTime=0 
2013-1-16 23:54:49 org.apache.solr.core.SolrCore execute
Info: [suit1] webapp=/vanclsearchV2 path=/select/ params={fl=id,typeid,createtime,vprice,sprice,price,totalassesscount,totalsalescount,productcode,productname,stylecode,tag,vpricesku,spricesku,pricesku,userrate,assesscount,lstphotos,mainphotos,salesflag,isduanma,detailsalescount,productplusstyleinfo&sort=createtime+desc&start=0&q=*:*&wt=json&fq=ancestorsid:(28976+OR+28978)&fq=typeid:(1)&rows=30} hits=43 status=0 QTime=0
2013-1-16 23:57:17 org.apache.solr.core.SolrCore execute
Info: [suit1] webapp=/vanclsearchV2 path=/select/ params={fl=id,typeid,createtime,vprice,sprice,price,totalassesscount,totalsalescount,productcode,productname,stylecode,tag,vpricesku,spricesku,pricesku,userrate,assesscount,lstphotos,mainphotos,salesflag,isduanma,detailsalescount,productplusstyleinfo&sort=createtime+desc&start=0&q=*:*&wt=json&fq=ancestorsid:(27547+OR+27614)&rows=30} hits=9 status=0 QTime=0 
2013-1-16 23:57:18 org.apache.solr.core.SolrCore execute
Info: [suit1] webapp=/vanclsearchV2 path=/select/ params={fl=id,typeid,createtime,vprice,sprice,price,totalassesscount,totalsalescount,productcode,productname,stylecode,tag,vpricesku,spricesku,pricesku,userrate,assesscount,lstphotos,mainphotos,salesflag,isduanma,detailsalescount,productplusstyleinfo&sort=createtime+desc&start=0&q=*:*&wt=json&fq=ancestorsid:(27547+OR+27614)&rows=30} hits=9 status=0 QTime=0

Every strange, all the QTime were zero! Can anyone explain this circumstance, and how to solve the problem?

string QUERY_TEMPLATE = ConfigurationManager.AppSettings["solr-select-url"] + "/select/?fl={0}&q={1}{2}&start={3}&rows={4}&sort={5}&wt=json";

WebRequest request = HttpWebRequest.Create(string.Format(QUERY_TEMPLATE,
                                                requestInfo.BrowserType==BrowserTypeEnum.Style?STYLE_FIELDS:COLOR_FIELDS,
                                                string.IsNullOrWhiteSpace(requestInfo.KeyWord) ? "*:*" : requestInfo.KeyWord,
                                                filterQuery,
                                                (requestInfo.Page - 1) * requestInfo.RowsCount,
                                                requestInfo.RowsCount,
                                                sortFiled)
                                            );
request.Method="GET";

string resultString=null;

Stopwatch solrWatch = new Stopwatch();
solrWatch.Start();
using (WebResponse response = request.GetResponse())
{
    using (Stream stream = response.GetResponseStream())
    {
        using (StreamReader reader = new StreamReader(stream))
        {
            resultString = reader.ReadToEnd();
        }
    }
}
solrWatch.Stop();
solrTime = solrWatch.ElapsedMilliseconds;

Upvotes: 0

Views: 508

Answers (2)

Alexandre Rafalovitch
Alexandre Rafalovitch

Reputation: 9789

The QTime is the time for Solr to do its search. The rest of the time is taken by generating the response, including fetching the stored content of the fields from the disk and generating them into the JSON form.

I would look into the following couple of things:

  • Using SolrNet library to access Solr instead of doing your own queries and parsing the responses
  • Checking whether you are sending debug information and turning that off; just look at returned JSON and configure it in the solrconfig.xml
  • Checking if you really need all those fields in response
  • Checking if any particular field is really big and whether you are bottle-necked by disk rather than CPU; if so, you could (in Solr 4) declare that field to be stored as compressed - that could speed up getting the field from the disk

Upvotes: 2

Paige Cook
Paige Cook

Reputation: 22555

Thanks for adding the code you are using to access the Solr server. The request to Solr is happening very quickly as evidenced from your tomcat logs. (Solr is caching the query and therfore the QTime is 0 as you noted). Your 1000+ ms of time is not for the Solr server to respond to you. That time is being spent to transfer the Solr response back to your client (trivial in this case since it is on the same server) and read the response stream.

Additionally, you might want to consider using the SolrNet client to access Solr from C#. It provides a much richer interface for querying to Solr and will map the query results to POCO objects.

Upvotes: 0

Related Questions