On 9/27/2013 8:37 AM, Shawn Heisey wrote:
> INFO - 2013-09-27 08:27:00.806;
> org.apache.solr.update.processor.LogUpdateProcessor; [inclive]
> webapp=/solr path=/update params={wt=javabin&version=2}
> {add=[notimexpix438424 (1447341085818880000), notimexpix438425
> (1447341085825171456), notimexpix438426 (1447341085826220032),
> notimexpix438427 (1447341085826220033), notimexpix438428
> (1447341085827268608), notimexpix438429(1447341085828317184),
> notimexpix438430 (1447341085829365760), notimexpix438431
> (1447341085830414336), notimexpix438432 (1447341085831462912),
> notimexpix438433 (1447341085831462913), ... (66 adds)]} 0 181
>
> INFO - 2013-09-27 08:27:01.975;
> org.apache.solr.update.processor.LogUpdateProcessor; [inclive]
> webapp=/solr path=/update
> params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false}
> {commit=} 0 1065
>
> Note that the QTime doesn't represent the total amount of time for the
> request, because it only measures the part that's in under the control
> of the specific class that's generating the log - in this case
> LogUpdateProcessor. It can't measure the time the servlet container
> takes to handle the HTTP conversation, or any part of the request that
> takes place in Solr classes called before or after LogUpdateProcessor.
I can illustrate the difference between QTime and the actual transaction
time by showing you the log entries from the application that correspond
exactly to the Solr log entries I shared:
INFO - 2013-09-27 08:27:00.815; chain.c: Insert done, 66, time = 315
INFO - 2013-09-27 08:27:01.976; chain.c: Commit done, time = 1161
The add request with 66 documents had a QTime of 181, but took 315
milliseconds. The commit had a QTime of 1065, but actually took 1161
milliseconds.
Thanks,
Shawn
