solr 启动慢原因分析一则

赤色烙印

　　目前线上solr每个replica索引2G左右，每次重新启动需要10分钟，无法忍受。
　　观察solr的日志，发现打印红色部分前后用去了5分钟，前一条log“registering core”很具迷惑性，以为是注册core时耗费的时间，后来发现这个注册core和初始化SolrCore时的创建searcher不是同一个线程。真正耗费时间的时创建新的searcher的时候。[2014.08.13 16:45:07.624]11714 [searcherExecutor-8-thread-1] INFO  org.apache.solr.core.SolrCore  [autocplt] Registered new searcher Searcher@5feed5f2[autocplt] main{StandardDirectoryReader(segments_2cf:52943:nrt _e2o(4.7):C34398/51:delGen=1 _e2n(4.7):C14/1:delGen=1 _e2p(4.7):C16/5:delGen=2 _e2q(4.7):C9 _e2r(4.7):C29/6:delGen=1)}
[2014.08.13 16:45:07.627]11717 [coreLoadExecutor-4-thread-4] WARN  org.apache.solr.core.SolrCore  WARNING: RealTimeGetHandler is not registered at /get. SolrCloud will always use full index replication instead of the more efficient PeerSync method.
[2014.08.13 16:45:07.628]11717 [coreLoadExecutor-4-thread-4] INFO  org.apache.solr.core.CoreContainer  registering core: autocplt
<span style=&quot;color:#ff0000;&quot;>[2014.08.13 16:50:11.020]315109 [searcherExecutor-7-thread-1] INFO  org.apache.solr.core.SolrCore  [doc] Registered new searcher Searcher@b4914ab[doc] main{StandardDirectoryReader(segments_475:73489:nrt _jey(4.7):C10422529/2120186:delGen=333 _ize(4.7):C87432/7:delGen=4 _juk(4.7):C519699/27:delGen=18 _k0o(4.7):C446288/15:delGen=8 _ji1(4.7):C438273/12:delGen=6 _jnu(4.7):C422457/209:delGen=50 _jkt(4.7):C482990/205:delGen=68 _jgn(4.7):C29798/43:delGen=4 _jxm(4.7):C448227/5:delGen=2 _jr7(4.7):C477415/59:delGen=32 _jw8(4.7):C77157/7:delGen=4 _k18(4.7):C32746 _kv7(4.7):C39331/17:delGen=13 _k1r(4.7):C39768/10:delGen=5 _k1i(4.7):C35555/6:delGen=3 _k2l(4.7):C20458 _k22(4.7):C45921/2:delGen=2 _k2b(4.7):C48949/13:delGen=3 _kya(4.7):C664/1:delGen=1 _kyk(4.7):C710/1:delGen=1 _kyl(4.7):C6 _kym(4.7):C14 _kyn(4.7):C6 _kyo(4.7):C1 _kyp(4.7):C6 _kyq(4.7):C4 _kyr(4.7):C1 _kys(4.7):C9)}</span>
[2014.08.13 16:50:11.026]315115 [coreLoadExecutor-4-thread-1] WARN  org.apache.solr.core.SolrCore  WARNING: RealTimeGetHandler is not registered at /get. SolrCloud will always use full index replication instead of the more efficient PeerSync method.
[2014.08.13 16:50:11.026]315116 [coreLoadExecutor-4-thread-1] INFO  org.apache.solr.core.CoreContainer  registering core: doc
[2014.08.13 16:50:11.111]315200 [coreZkRegister-1-thread-1] INFO  org.apache.solr.cloud.ZkController  Register replica - core:editor address:http://XXX/solr collection:editorCollection shard:shard2
[2014.08.13 16:50:11.111]315201 [coreZkRegister-1-thread-3] INFO  org.apache.solr.cloud.ZkController  Register replica - core:autocplt address:http://XXX/solr collection:autocpltCollection shard:shard2
[2014.08.13 16:50:11.112]315201 [coreZkRegister-1-thread-4] INFO  org.apache.solr.cloud.ZkController  Register replica - core:doc address:http://XXX/solr collection:docCollection shard:shard2
[2014.08.13 16:50:11.113]315200 [coreZkRegister-1-thread-2] INFO  org.apache.solr.cloud.ZkController  Register replica - core:cgindex address:http://XXX/solr collection:cgindexCollection shard:shard2

　　



用jstack看了线程执行状况：&quot;searcherExecutor-8-thread-1&quot; prio=10 tid=0x0000000041183800 nid=0x79e5 runnable [0x00007fd69bff0000]
java.lang.Thread.State: RUNNABLE
at java.nio.Bits.copyToByteArray(Native Method)
at java.nio.DirectByteBuffer.get(DirectByteBuffer.java:224)
at org.apache.lucene.store.ByteBufferIndexInput.readBytes(ByteBufferIndexInput.java:92)
at org.apache.lucene.codecs.compressing.LZ4.decompress(LZ4.java:101)
at org.apache.lucene.codecs.compressing.CompressionMode$4.decompress(CompressionMode.java:135)
at org.apache.lucene.codecs.compressing.CompressingStoredFieldsReader.visitDocument(CompressingStoredFieldsReader.java:336)
at org.apache.lucene.index.SegmentReader.document(SegmentReader.java:279)
at org.apache.lucene.index.BaseCompositeReader.document(BaseCompositeReader.java:110)
at org.apache.lucene.index.IndexReader.document(IndexReader.java:457)
at org.apache.lucene.search.suggest.DocumentDictionary$DocumentInputIterator.next(DocumentDictionary.java:138)
at org.apache.lucene.search.suggest.analyzing.AnalyzingSuggester.build(AnalyzingSuggester.java:402)
at org.apache.lucene.search.suggest.Lookup.build(Lookup.java:165)
at org.apache.solr.spelling.suggest.SolrSuggester.build(SolrSuggester.java:142)
at org.apache.solr.spelling.suggest.SolrSuggester.reload(SolrSuggester.java:169)
at org.apache.solr.handler.component.SuggestComponent$SuggesterListener.newSearcher(SuggestComponent.java:465)
at org.apache.solr.core.SolrCore$5.call(SolrCore.java:1695)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
Locked ownable synchronizers:
- <0x00007fddf7093888> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)


&quot;coreLoadExecutor-4-thread-4&quot; prio=10 tid=0x00007fd9dc4f6000 nid=0x79e1 in Object.wait() [0x00007fd79bff4000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00007fddf4b15e60> (a java.lang.Object)
at java.lang.Object.wait(Object.java:485)
at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1590)
- locked <0x00007fddf4b15e60> (a java.lang.Object)
at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1390)
at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1325)
at org.apache.solr.handler.ReplicationHandler.getIndexVersion(ReplicationHandler.java:547)
at org.apache.solr.handler.ReplicationHandler.getStatistics(ReplicationHandler.java:564)
at org.apache.solr.core.JmxMonitoredMap$SolrDynamicMBean.getMBeanInfo(JmxMonitoredMap.java:236)
at com.caucho.jmx.MBeanWrapper.getMBeanInfo(MBeanWrapper.java:160)
at com.caucho.jmx.MBeanContext.getDebugName(MBeanContext.java:588)
at com.caucho.jmx.MBeanContext.addMBean(MBeanContext.java:364)
at com.caucho.jmx.MBeanContext.registerMBean(MBeanContext.java:251)
at com.caucho.jmx.AbstractMBeanServer.registerMBean(AbstractMBeanServer.java:440)
at org.apache.solr.core.JmxMonitoredMap.put(JmxMonitoredMap.java:140)
at org.apache.solr.core.JmxMonitoredMap.put(JmxMonitoredMap.java:51)
at org.apache.solr.core.SolrResourceLoader.inform(SolrResourceLoader.java:677)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:859)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:630)
at org.apache.solr.core.ZkContainer.createFromZk(ZkContainer.java:245)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:595)
at org.apache.solr.core.CoreContainer$1.call(CoreContainer.java:258)
at org.apache.solr.core.CoreContainer$1.call(CoreContainer.java:250)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
Locked ownable synchronizers:
- <0x00007fdf0b089748> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)


&quot;main&quot; prio=10 tid=0x000000004089d800 nid=0x79b9 waiting on condition [0x00007feaadd32000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00007fdf09bee000> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
at java.util.concurrent.ExecutorCompletionService.take(ExecutorCompletionService.java:164)
at org.apache.solr.core.CoreContainer.load(CoreContainer.java:293)
at org.apache.solr.servlet.SolrDispatchFilter.createCoreContainer(SolrDispatchFilter.java:187)
at org.apache.solr.servlet.SolrDispatchFilter.init(SolrDispatchFilter.java:134)
at com.caucho.server.dispatch.FilterManager.createFilter(FilterManager.java:134)
- locked <0x00007fdf09bee2d0> (a com.caucho.server.dispatch.FilterConfigImpl)
at com.caucho.server.dispatch.FilterManager.init(FilterManager.java:87)
at com.caucho.server.webapp.Application.start(Application.java:1655)
at com.caucho.server.deploy.DeployController.startImpl(DeployController.java:621)
at com.caucho.server.deploy.StartAutoRedeployAutoStrategy.startOnInit(StartAutoRedeployAutoStrategy.java:72)
at com.caucho.server.deploy.DeployController.startOnInit(DeployController.java:509)
at com.caucho.server.deploy.DeployContainer.start(DeployContainer.java:153)
at com.caucho.server.webapp.ApplicationContainer.start(ApplicationContainer.java:670)
at com.caucho.server.host.Host.start(Host.java:420)
at com.caucho.server.deploy.DeployController.startImpl(DeployController.java:621)
at com.caucho.server.deploy.StartAutoRedeployAutoStrategy.startOnInit(StartAutoRedeployAutoStrategy.java:72)
at com.caucho.server.deploy.DeployController.startOnInit(DeployController.java:509)
at com.caucho.server.deploy.DeployContainer.start(DeployContainer.java:153)
at com.caucho.server.host.HostContainer.start(HostContainer.java:504)
at com.caucho.server.resin.ServletServer.start(ServletServer.java:971)
at com.caucho.server.deploy.DeployController.startImpl(DeployController.java:621)
at com.caucho.server.deploy.AbstractDeployControllerStrategy.start(AbstractDeployControllerStrategy.java:56)
at com.caucho.server.deploy.DeployController.start(DeployController.java:517)
at com.caucho.server.resin.ResinServer.start(ResinServer.java:551)
at com.caucho.server.resin.Resin.init(Resin.java)
at com.caucho.server.resin.Resin.main(Resin.java:625)
Locked ownable synchronizers:
- None
　　



可见main中是停在了Future<SolrCore> future = completionService.take();等待线程执行完成，coreLoadExecutor-4-thread-4是停在了searcherLock.wait();　　等待被唤醒，而searcherExecutor-8-thread-1一直在读文件，并且是component.SuggestComponent在操作，由于solrconfig.xml里配置了suggest，但是suggest功能单独做了拼音索引，没有使用solr的这个suggest功能，去掉了solrconfig.xml中得相关配置，启动时间由10分钟变为了10s。
　　solr提供的suggest功能由线程栈大概可以看出都做了哪些操作，还进行了压缩，有时间时仔细看看源码。
　　


　　



版权声明：本文为博主原创文章，未经博主允许不得转载。