Hi,
We have Solr Cloud (version 4.7.2) setup on 64 shards spread across VMs. I
see my queries to Solr taking exactly 50 sec intermittently (as someone
said so :P). This happens once in 10 queries.
I have enabled log level to TRACE on all the solr nodes. I didn't find any
issue with the query time on any given shard (max QTime observed on a shard
is 10 ms). We ran all the tests related to network and everything looks
fine there.
Whenever the query took 50 sec, I am seeing the below log statements
for org.eclipse.jetty component. Is this some issue with Jetty?? I could
see this logs being printed every 11 seconds(*2015-07-24 07:06:00, **2015-07-24
07:06:11, ...)* for 4 times. Attached the complete logs during that
duration. Can someone please help me here??
*DEBUG - 2015-07-24 07:06:00.126; org.eclipse.jetty.http.HttpParser; filled
707/707*
*DEBUG - 2015-07-24 07:06:00.127; org.eclipse.jetty.server.Server; REQUEST
/solr/admin/info/logging on
BlockingHttpConnection@7a5f39b0,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=-5,l=209,c=0},r=43*
*DEBUG - 2015-07-24 07:06:00.127;
org.eclipse.jetty.server.handler.ContextHandler; scope
null||/solr/admin/info/logging @
o.e.j.w.WebAppContext{/solr,file:/u01/work/app/install_solr/daas_node/solr-webapp/webapp/},/u01/work/app/install_solr/daas_node/webapps/solr.war*
*DEBUG - 2015-07-24 07:06:00.127;
org.eclipse.jetty.server.handler.ContextHandler;
context=/solr||/admin/info/logging @
o.e.j.w.WebAppContext{/solr,file:/u01/work/app/install_solr/daas_node/solr-webapp/webapp/},/u01/work/app/install_solr/daas_node/webapps/solr.war*
*DEBUG - 2015-07-24 07:06:00.127;
org.eclipse.jetty.server.session.SessionHandler; Got Session ID
vZScVxfQ528bXYGHJw16N3vTLJ4t3L41bSkHNmyTywQKGGzZFC8p!-348395136!NONE from
cookie*
*DEBUG - 2015-07-24 07:06:00.127;
org.eclipse.jetty.server.session.SessionHandler;
sessionManager=org.eclipse.jetty.server.session.HashSessionManager@1c49094*
*DEBUG - 2015-07-24 07:06:00.127;
org.eclipse.jetty.server.session.SessionHandler; session=null*
*DEBUG - 2015-07-24 07:06:00.128; org.eclipse.jetty.servlet.ServletHandler;
servlet /solr|/admin/info/logging|null -> default*
*DEBUG - 2015-07-24 07:06:00.128; org.eclipse.jetty.servlet.ServletHandler;
chain=SolrRequestFilter->default*
*DEBUG - 2015-07-24 07:06:00.128;
org.eclipse.jetty.servlet.ServletHandler$CachedChain; call filter
SolrRequestFilter*
*INFO - 2015-07-24 07:06:00.128;
org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null
path=/admin/info/logging
params={_=1437736005493&since=1437734905469&wt=json} status=0 QTime=0 *
*DEBUG - 2015-07-24 07:06:00.128;
org.apache.solr.servlet.SolrDispatchFilter; Closing out SolrRequest:
{_=1437736005493&since=1437734905469&wt=json}*
*DEBUG - 2015-07-24 07:06:00.129; org.eclipse.jetty.server.Server; RESPONSE
/solr/admin/info/logging 200 handled=true*
*DEBUG - 2015-07-24 07:06:06.327;
org.apache.zookeeper.ClientCnxn$SendThread; Got ping response for
sessionid: 0x14eaf8f79530460 after 0ms*
*DEBUG - 2015-07-24 07:06:11.118; org.eclipse.jetty.http.HttpParser; filled
707/707*
*DEBUG - 2015-07-24 07:06:11.119; org.eclipse.jetty.server.Server; REQUEST
/solr/admin/info/logging on
BlockingHttpConnection@7a5f39b0,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=-5,l=209,c=0},r=44*
*DEBUG - 2015-07-24 07:06:11.119;
org.eclipse.jetty.server.handler.ContextHandler; scope
null||/solr/admin/info/logging @
o.e.j.w.WebAppContext{/solr,file:/u01/work/app/install_solr/daas_node/solr-webapp/webapp/},/u01/work/app/install_solr/daas_node/webapps/solr.war*
*DEBUG - 2015-07-24 07:06:11.119;
org.eclipse.jetty.server.handler.ContextHandler;
context=/solr||/admin/info/logging @
o.e.j.w.WebAppContext{/solr,file:/u01/work/app/install_solr/daas_node/solr-webapp/webapp/},/u01/work/app/install_solr/daas_node/webapps/solr.war*
*DEBUG - 2015-07-24 07:06:11.119;
org.eclipse.jetty.server.session.SessionHandler; Got Session ID
vZScVxfQ528bXYGHJw16N3vTLJ4t3L41bSkHNmyTywQKGGzZFC8p!-348395136!NONE from
cookie*
*DEBUG - 2015-07-24 07:06:11.119;
org.eclipse.jetty.server.session.SessionHandler;
sessionManager=org.eclipse.jetty.server.session.HashSessionManager@1c49094*
*DEBUG - 2015-07-24 07:06:11.119;
org.eclipse.jetty.server.session.SessionHandler; session=null*
*DEBUG - 2015-07-24 07:06:11.120; org.eclipse.jetty.servlet.ServletHandler;
servlet /solr|/admin/info/logging|null -> default*
*DEBUG - 2015-07-24 07:06:11.120; org.eclipse.jetty.servlet.ServletHandler;
chain=SolrRequestFilter->default*
*DEBUG - 2015-07-24 07:06:11.120;
org.eclipse.jetty.servlet.ServletHandler$CachedChain; call filter
SolrRequestFilter*
*INFO - 2015-07-24 07:06:11.120;
org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null
path=/admin/info/logging
params={_=1437736016484&since=1437734905469&wt=json} status=0 QTime=0 *
*DEBUG - 2015-07-24 07:06:11.120;
org.apache.solr.servlet.SolrDispatchFilter; Closing out SolrRequest:
{_=1437736016484&since=1437734905469&wt=json}*
*DEBUG - 2015-07-24 07:06:11.121; org.eclipse.jetty.server.Server; RESPONSE
/solr/admin/info/logging 200 handled=true*
Thanks,
Manohar
