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 Jithin <ji...@gmail.com> on 2012/01/01 07:27:15 UTC

Interpreting solr response time from log

Hi,
For this request  curl 'solrhost:8983/solr/core0/admin/ping' response is

<?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int>*<int
name="QTime">2</int>*<lst name="params"><str
name="spellcheck">false</str><str name="echoParams">all</str><str
name="facet.mincount">1</str><str name="spellcheck.count">10</str><str
name="spellcheck.collate">true</str><str
name="spellcheck.onlyMorePopular">false</str><str name="rows">10</str><str
name="echoParams">all</str><str name="q">solrpingquery</str><str
name="qt">search</str></lst></lst><str name="status">OK</str>
</response>

which indicates response time is 2 ms.

But in solr log its been seen as 01/Jan/2012:06:25:16 +0000] "GET
/solr/core0/admin/ping HTTP/1.1" 200 *544*

Can anyone please explain to me why the logs is showing 544 ms as response
time? (My understanding is that the past parameter 544 is the response time)


--
View this message in context: http://lucene.472066.n3.nabble.com/Interpreting-solr-response-time-from-log-tp3624340p3624340.html
Sent from the Solr - User mailing list archive at Nabble.com.

Re: Interpreting solr response time from log

Posted by Jithin <ji...@gmail.com>.
Thans Chris for clarifying. This helps a lot.

On Wed, Jan 4, 2012 at 2:07 AM, Chris Hostetter-3 [via Lucene] <
ml-node+s472066n3630181h29@n3.nabble.com> wrote:

> : If your log level is set at least to INFO, as it should be by default
> Solr does
> : log response time to a different file. E.g., I have
> : INFO: [] webapp=/solr path=/select/
> : params={indent=on&start=0&q=*:*&version=2.2&rows=10} hits=22 status=0
> : QTime=40
> : where the QTime is 40ms, as also reflected in the HTTP response. You
>
> It's also really important to understand exactly what QTime is measuring.
>
>
> I've added a FAQ to try and make this more obvious...
>
>
> https://wiki.apache.org/solr/FAQ#Why_is_the_QTime_Solr_returns_lower_then_the_amount_of_time_I.27m_measuring_in_my_client.3F
>
> -Hoss
>
>
> ------------------------------
>  If you reply to this email, your message will be added to the discussion
> below:
>
> http://lucene.472066.n3.nabble.com/Interpreting-solr-response-time-from-log-tp3624340p3630181.html
>  To unsubscribe from Interpreting solr response time from log, click here<http://lucene.472066.n3.nabble.com/template/NamlServlet.jtp?macro=unsubscribe_by_code&node=3624340&code=aml0aGluMTk4N0BnbWFpbC5jb218MzYyNDM0MHwtMTEwMTgwMTA3Ng==>
> .
> NAML<http://lucene.472066.n3.nabble.com/template/NamlServlet.jtp?macro=macro_viewer&id=instant_html%21nabble%3Aemail.naml&base=nabble.naml.namespaces.BasicNamespace-nabble.view.web.template.NabbleNamespace-nabble.view.web.template.InstantMailNamespace&breadcrumbs=instant+emails%21nabble%3Aemail.naml-instant_emails%21nabble%3Aemail.naml-send_instant_email%21nabble%3Aemail.naml>
>



-- 
Thanks
Jithin Emmanuel


--
View this message in context: http://lucene.472066.n3.nabble.com/Interpreting-solr-response-time-from-log-tp3624340p3630843.html
Sent from the Solr - User mailing list archive at Nabble.com.

Re: Interpreting solr response time from log

Posted by Chris Hostetter <ho...@fucit.org>.
: If your log level is set at least to INFO, as it should be by default Solr does
: log response time to a different file. E.g., I have
: INFO: [] webapp=/solr path=/select/
: params={indent=on&start=0&q=*:*&version=2.2&rows=10} hits=22 status=0
: QTime=40
: where the QTime is 40ms, as also reflected in the HTTP response. You

It's also really important to understand exactly what QTime is measuring.  

I've added a FAQ to try and make this more obvious...

https://wiki.apache.org/solr/FAQ#Why_is_the_QTime_Solr_returns_lower_then_the_amount_of_time_I.27m_measuring_in_my_client.3F

-Hoss

Re: Interpreting solr response time from log

Posted by Gora Mohanty <go...@mimirtech.com>.
On Sun, Jan 1, 2012 at 8:58 PM, Jithin <ji...@gmail.com> wrote:
> Thanks Gora for clarifying. So if my understanding is correct then the total
> response time is not logged in solr logs and I need to rely on the QTime in
> the response.

If your log level is set at least to INFO, as it should be by default Solr does
log response time to a different file. E.g., I have
INFO: [] webapp=/solr path=/select/
params={indent=on&start=0&q=*:*&version=2.2&rows=10} hits=22 status=0
QTime=40
where the QTime is 40ms, as also reflected in the HTTP response. You
were looking at the request logs in your example. This information is
logged to standard output (usually, terminal) by the Jetty embedded in
Solr (i.e., if you are doing "java -jar start.jar"), or to catalina.out if Solr
is used with Tomcat.

Regards,
Gora

Re: Interpreting solr response time from log

Posted by Jithin <ji...@gmail.com>.
Thanks Gora for clarifying. So if my understanding is correct then the total
response time is not logged in solr logs and I need to rely on the QTime in
the response.

--
View this message in context: http://lucene.472066.n3.nabble.com/Interpreting-solr-response-time-from-log-tp3624340p3624931.html
Sent from the Solr - User mailing list archive at Nabble.com.

Re: Interpreting solr response time from log

Posted by Gora Mohanty <go...@mimirtech.com>.
On Sun, Jan 1, 2012 at 11:57 AM, Jithin <ji...@gmail.com> wrote:
[...]
> which indicates response time is 2 ms.
>
> But in solr log its been seen as 01/Jan/2012:06:25:16 +0000] "GET
> /solr/core0/admin/ping HTTP/1.1" 200 *544*

> Can anyone please explain to me why the logs is showing 544 ms as response
> time? (My understanding is that the past parameter 544 is the response time)

I believe that "544" is the length of the HTTP response, and not the time.

Regards,
Gora