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="color:#ff0000;">[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看了线程执行状况：

"searcherExecutor-8-thread-1" prio=10 tid=0x0000000041183800 nid=0x79e5 runnable [0x00007fd69bff0000]   java.lang.Thread.State: RUNNABLEat 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)"coreLoadExecutor-4-thread-4" 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)"main" 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功能由线程栈大概可以看出都做了哪些操作，还进行了压缩，有时间时仔细看看源码。