Hi Erick,
In solr.xml file I had zk timeout set to* <int
name="zkClientTimeout">${zkClientTimeout:450000}</int>*
One thing that made a it a bit better now is the zk tick time and syncLimit
settings. I set it to a higher value as below. This may not be advisable
though.
tickTime=30000
initLimit=30
syncLimit=20
Now we observed that replicas do not go in recovery that often as before.
In the whole cluster at a given time I would have a couple of replicas in
recovery whereas earlier it were multiple replicas from every shard .
On the wiki https://wiki.apache.org/solr/SolrCloud it says the "The maximum
is 20 times the tickTime." in the FAQ so I decided to increase the tick
time. Is this the correct approach ?
One question I have is that if auto commit settings has anything to do with
this or not ? Does it induce extra work for the searchers because of which
this would happen? I have tried with following settings
* <autoSoftCommit>*
* <maxDocs>500000</maxDocs>*
* <maxTime>900000</maxTime>*
* </autoSoftCommit>*
* <autoCommit>*
* <maxDocs>200000</maxDocs>*
* <maxTime>30000</maxTime>*
* <openSearcher>false</openSearcher>*
* </autoCommit>*
I have increased the heap size to 15GB for each JVM instance . I
monitored during full indexing how the heap usage looks like and it never
goes beyond 8 GB . I don't see any Full GC happening at any point .
I had some attached screenshots but they were marked as spam so not sending
them again
Our rate is a variable rate . It is not a sustained rate of 6000/second ,
however there are intervals where it would reach that much and come down
and grow again and come down. So if I would take an average it would be
600/second only but that is not real rate at any given time.
Version of solr cloud is 4.10. All indexers are basically java programs
running on different host using CloudSolrServer api.
As I mentioned it is much better now than before , however not completely
as expected . We would want none of them to go in recovery if really there
is no need.
I captured some logs before and after recovery
4:13:54,298 INFO [org.apache.solr.handler.SnapPuller] (RecoveryThread)
New index installed. Updating index properties...
index=index.20150126140904697
14:13:54,301 INFO [org.apache.solr.handler.SnapPuller] (RecoveryThread)
removing old index directory
NRTCachingDirectory(MMapDirectory@/opt/solr/solrnodes/solrnode1/search1_shard7_replica4/data/index.20150126134945417
lockFactory=NativeFSLockFactory@/opt/solr/solrnodes/solrnode1/search1_shard7_replica4/data/index.20150126134945417;
maxCacheMB=48.0 maxMergeSizeMB=4.0)
14:13:54,302 INFO [org.apache.solr.update.DefaultSolrCoreState]
(RecoveryThread) Creating new IndexWriter...
14:13:54,302 INFO [org.apache.solr.update.DefaultSolrCoreState]
(RecoveryThread) Waiting until IndexWriter is unused...
core=search1_shard7_replica4
14:13:54,302 INFO [org.apache.solr.update.DefaultSolrCoreState]
(RecoveryThread) Rollback old IndexWriter... core=search1_shard7_replica4
14:13:54,302 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [IW][RecoveryThread]: rollback
14:13:54,302 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [IW][RecoveryThread]: all running merges have aborted
14:13:54,302 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [IW][RecoveryThread]: rollback: done finish merges
14:13:54,302 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [DW][RecoveryThread]: abort
14:13:54,303 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [DW][RecoveryThread]: done abort; abortedFiles=[]
success=true
14:13:54,306 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [IW][RecoveryThread]: rollback:
infos=_4qe(4.10.0):C4312879/1370002:delGen=56
_554(4.10.0):C3995865/780418:delGen=23 _56u(4.10.0):C286775/11906:delGen=15
_5co(4.10.0):C871785/93841:delGen=10 _5m7(4.10.0):C122852/31645:delGen=11
_5hm(4.10.0):C457977/32465:delGen=11 _5q2(4.10.0):C13189/649:delGen=6
_5kb(4.10.0):C424868/19148:delGen=11 _5f5(4.10.0):C116528/42495:delGen=1
_5nx(4.10.0):C33236/20668:delGen=1 _5ql(4.10.0):C25924/2:delGen=2
_5o8(4.10.0):C27155/7531:delGen=1 _5of(4.10.0):C38545/5677:delGen=1
_5p7(4.10.0):C37457/648:delGen=1 _5r5(4.10.0):C4260 _5qv(4.10.0):C1750
_5qi(4.10.0):C842 _5qp(4.10.0):C2247 _5qm(4.10.0):C2214 _5qo(4.10.0):C1785
_5qn(4.10.0):C1962 _5qu(4.10.0):C2390 _5qy(4.10.0):C2129 _5qx(4.10.0):C2192
_5qw(4.10.0):C2157/1:delGen=1 _5r6(4.10.0):C159 _5r4(4.10.0):C742
_5r8(4.10.0):C334 _5r7(4.10.0):C390 _5r3(4.10.0):C1122
14:13:54,306 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [IFD][RecoveryThread]: now checkpoint
"_4qe(4.10.0):C4312879/1370002:delGen=56
_554(4.10.0):C3995865/780418:delGen=23 _56u(4.10.0):C286775/11906:delGen=15
_5co(4.10.0):C871785/93841:delGen=10 _5m7(4.10.0):C122852/31645:delGen=11
_5hm(4.10.0):C457977/32465:delGen=11 _5q2(4.10.0):C13189/649:delGen=6
_5kb(4.10.0):C424868/19148:delGen=11 _5f5(4.10.0):C116528/42495:delGen=1
_5nx(4.10.0):C33236/20668:delGen=1 _5ql(4.10.0):C25924/2:delGen=2
_5o8(4.10.0):C27155/7531:delGen=1 _5of(4.10.0):C38545/5677:delGen=1
_5p7(4.10.0):C37457/648:delGen=1 _5r5(4.10.0):C4260 _5qv(4.10.0):C1750
_5qi(4.10.0):C842 _5qp(4.10.0):C2247 _5qm(4.10.0):C2214 _5qo(4.10.0):C1785
_5qn(4.10.0):C1962 _5qu(4.10.0):C2390 _5qy(4.10.0):C2129 _5qx(4.10.0):C2192
_5qw(4.10.0):C2157/1:delGen=1 _5r6(4.10.0):C159 _5r4(4.10.0):C742
_5r8(4.10.0):C334 _5r7(4.10.0):C390 _5r3(4.10.0):C1122" [30 segments ;
isCommit = false]
14:13:54,307 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [IFD][RecoveryThread]: 0 msec to checkpoint
14:13:54,323 INFO [org.apache.solr.core.SolrCore] (RecoveryThread) New
index directory detected:
old=/opt/solr/solrnodes/solrnode1/search1_shard7_replica4/data/index.20150126134945417
new=/opt/solr/solrnodes/solrnode1/search1_shard7_replica4/data/index.20150126140904697
14:13:54,417 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [IFD][RecoveryThread]: init: current segments file is
"segments_9t";
deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@592ddff6
14:13:54,420 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [IFD][RecoveryThread]: init: load commit "segments_9t"
14:13:54,424 INFO [org.apache.solr.core.SolrCore] (RecoveryThread)
SolrDeletionPolicy.onInit: commits: num=1
commit{dir=NRTCachingDirectory(MMapDirectory@
/opt/solr/solrnodes/solrnode1/search1_shard7_replica4/data/index.20150126140904697
ersion=4.10.0
matchVersion=4.8.0
analyzer=null
ramBufferSizeMB=100.0
maxBufferedDocs=-1
maxBufferedDeleteTerms=-1
mergedSegmentWarmer=null
readerTermsIndexDivisor=1
termIndexInterval=32
delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
commit=null
openMode=APPEND
similarity=com.shc.solrx.similarity.CustomSimilarity
mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2,
mergeThreadPriority=-1
default WRITE_LOCK_TIMEOUT=1000
writeLockTimeout=1000
codec=Lucene410
infoStream=org.apache.solr.update.LoggingInfoStream
mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10,
maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0,
forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0,
maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@693825c0
readerPooling=false
perThreadHardLimitMB=1945
useCompoundFile=false
checkIntegrityAtMerge=false
writer=org.apache.lucene.util.SetOnce@65369637
14:13:54,425 INFO [org.apache.solr.update.DefaultSolrCoreState]
(RecoveryThread) New IndexWriter is ready to be used.
14:13:54,425 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [IW][RecoveryThread]: flush at getReader
14:13:54,425 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [DW][RecoveryThread]: startFullFlush
14:13:54,426 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [DW][RecoveryThread]: anyChanges? numDocsInRam=0
deletes=false hasTickets:false pendingChangesInFullFlush: false
14:13:54,426 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [IW][RecoveryThread]: apply all deletes during flush
14:13:54,426 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [BD][RecoveryThread]: applyDeletes: no deletes; skipping
14:13:54,426 INFO [org.apache.solr.update.LoggingInfoStream]
(RecoveryThread) [BD][RecoveryThread]: prune sis=segments_9t:
_4qe(4.10.0):C4312879/1370002
lrx334p.qa.ch3.s.com:8680/solr/search1_shard7_replica11/&update.distrib=FROMLEADER&wt=javabin&version=2&update.chain=script&update.chain=removeDuplicates}
status=0 QTime=0
14:16:49,279 INFO [org.apache.solr.core.SolrCore] (http-/10.235.47.41:8580-1)
[search1_shard7_replica4] webapp=/solr path=/update params={distrib.from=
http://solrx334p.qa.ch3.s.com:8680/solr/search1_shard7_replica11/&update.distrib=FROMLEADER&wt=javabin&version=2&update.chain=script&update.chain=removeDuplicates}
status=0 QTime=0
14:16:49,283 INFO [org.apache.solr.update.UpdateHandler]
(recoveryExecutor-7-thread-1) start
commit{flags=2,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
14:16:49,283 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]: commit:
start
14:16:49,283 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]: commit:
enter lock
14:16:49,283 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]: commit:
now prepare
14:16:49,283 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]:
prepareCommit: flush
14:16:49,283 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]: index
before flush _4qe(4.10.0):C4312879/1370002:delGen=56
_554(4.10.0):C3995865/780418:delGen=23 _56u(4.10.0):C286775/11906:delGen=15
_5co(4.10.0):C871785/93841:delGen=10 _5m7(4.10.0):C122852/31675:delGen=11
_5hm(4.10.0):C457977/32535:delGen=11 _5q0(4.10.0):C13610/649:delGen=6
_5kb(4.10.0):C424868/19149:delGen=11 _5f5(4.10.0):C116528/42495:delGen=1
_5nx(4.10.0):C33236/20668:delGen=1 _5qm(4.10.0):C29770/1:delGen=1
_5o8(4.10.0):C27155/7531:delGen=1 _5of(4.10.0):C38545/5677:delGen=1
_5p7(4.10.0):C37457/648:delGen=1 _5qv(4.10.0):C3973
_5q1(4.10.0):C402/1:delGen=1 _5q2(4.10.0):C779 _5qa(4.10.0):C967
_5qc(4.10.0):C1828 _5qh(4.10.0):C1765 _5qi(4.10.0):C1241 _5qq(4.10.0):C1997
_5qr(4.10.0):C1468 _5qp(4.10.0):C1729 _5qo(4.10.0):C3456/1:delGen=1
_5qu(4.10.0):C27 _5qt(4.10.0):C30 _5qx(4.10.0):C638 _5qy(4.10.0):C1407
_5qw(4.10.0):C802 _5r2(4.10.0):C32769/1:delGen=1 _5r3(4.10.0):C26057
_5r4(4.10.0):C23934/1:delGen=1
14:16:49,283 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [DW][recoveryExecutor-7-thread-1]:
startFullFlush
14:16:49,284 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [DW][recoveryExecutor-7-thread-1]:
anyChanges? numDocsInRam=24222 deletes=true hasTickets:false
pendingChangesInFullFlush: false
14:16:49,284 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [DWFC][recoveryExecutor-7-thread-1]:
addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 24221
deleted terms (unique count=24220) bytesUsed=4455794, segment=_5r5,
aborting=false, numDocsInRAM=24222, deleteQueue=DWDQ: [ generation: 1 ]]
14:16:49,322 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [DWPT][recoveryExecutor-7-thread-1]: flush
postings as segment _5r5 numDocs=24222
==> gc.20150126-135638.log <==
1211.362: [GC1211.362: [ParNew: 966947K->88429K(996800K), 0.0191260 secs]
1499845K->633603K(1995752K), 0.0192710 secs] [Times: user=0.20 sys=0.00,
real=0.02 secs]
==> server.log <==
14:16:50,387 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [DWPT][recoveryExecutor-7-thread-1]: new
segment has 1 deleted docs
14:16:50,387 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [DWPT][recoveryExecutor-7-thread-1]: new
segment has no vectors; no norms; no docValues; prox; freqs
14:16:50,387 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [DWPT][recoveryExecutor-7-thread-1]:
flushedFiles=[_5r5_Lucene41_0.pos, _5r5.fdx, _5r5.fnm, _5r5.fdt,
_5r5_Lucene41_0.tim, _5r5_Lucene41_0.tip, _5r5_Lucene41_0.doc]
14:16:50,387 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [DWPT][recoveryExecutor-7-thread-1]: flushed
codec=Lucene410
14:16:50,387 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [DWPT][recoveryExecutor-7-thread-1]: flushed:
segment=_5r5 ramUsed=75.564 MB newFlushedSize(includes docstores)=19.546 MB
docs/MB=1,239.201
14:16:50,387 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [DWPT][recoveryExecutor-7-thread-1]: flush:
write 1 deletes gen=-1
14:16:50,388 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [DW][recoveryExecutor-7-thread-1]:
publishFlushedSegment seg-private updates=null
14:16:50,388 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]:
publishFlushedSegment
14:16:50,388 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [BD][recoveryExecutor-7-thread-1]: push
deletes 24222 deleted terms (unique count=24221) bytesUsed=286752 delGen=8
packetCount=4 totBytesUsed=1259648
14:16:50,388 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]: publish
sets newSegment delGen=9 seg=_5r5(4.10.0):C24222/1:delGen=1
14:16:50,388 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IFD][recoveryExecutor-7-thread-1]: now
checkpoint "_4qe(4.10.0):C4312879/1370002:delGen=56
_554(4.10.0):C3995865/780418:delGen=23 _56u(4.10.0):C286775/11906:delGen=15
_5co(4.10.0):C871785/93841:delGen=10 _5m7(4.10.0):C122852/31675:delGen=11
_5hm(4.10.0):C457977/32535:delGen=11 _5q0(4.10.0):C13610/649:delGen=6
_5kb(4.10.0):C424868/19149:delGen=11 _5f5(4.10.0):C116528/42495:delGen=1
_5nx(4.10.0):C33236/20668:delGen=1 _5qm(4.10.0):C29770/1:delGen=1
_5o8(4.10.0):C27155/7531:delGen=1 _5of(4.10.0):C38545/5677:delGen=1
_5p7(4.10.0):C37457/648:delGen=1 _5qv(4.10.0):C3973
_5q1(4.10.0):C402/1:delGen=1 _5q2(4.10.0):C779 _5qa(4.10.0):C967
_5qc(4.10.0):C1828 _5qh(4.10.0):C1765 _5qi(4.10.0):C1241 _5qq(4.10.0):C1997
_5qr(4.10.0):C1468 _5qp(4.10.0):C1729 _5qo(4.10.0):C3456/1:delGen=1
_5qu(4.10.0):C27 _5qt(4.10.0):C30 _5qx(4.10.0):C638 _5qy(4.10.0):C1407
_5qw(4.10.0):C802 _5r2(4.10.0):C32769/1:delGen=1 _5r3(4.10.0):C26057
_5r4(4.10.0):C23934/1:delGen=1 _5r5(4.10.0):C24222/1:delGen=1" [34 segments
; isCommit = false]
14:16:50,388 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IFD][recoveryExecutor-7-thread-1]: 0 msec to
checkpoint
14:16:50,388 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]: apply all
deletes during flush
14:16:50,388 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [BD][recoveryExecutor-7-thread-1]:
applyDeletes: infos=[_4qe(4.10.0):C4312879/1370002:delGen=56,
_554(4.10.0):C3995865/780418:delGen=23,
_56u(4.10.0):C286775/11906:delGen=15, _5co(4.10.0):C871785/93841:delGen=10,
_5m7(4.10.0):C122852/31675:delGen=11, _5hm(4.10.0):C457977/32535:delGen=11,
_5q0(4.10.0):C13610/649:delGen=6, _5kb(4.10.0):C424868/19149:delGen=11,
_5f5(4.10.0):C116528/42495:delGen=1, _5nx(4.10.0):C33236/20668:delGen=1,
_5qm(4.10.0):C29770/1:delGen=1, _5o8(4.10.0):C27155/7531:delGen=1,
_5of(4.10.0):C38545/5677:delGen=1, _5p7(4.10.0):C37457/648:delGen=1,
_5qv(4.10.0):C3973, _5q1(4.10.0):C402/1:delGen=1, _5q2(4.10.0):C779,
_5qa(4.10.0):C967, _5qc(4.10.0):C1828, _5qh(4.10.0):C1765,
_5qi(4.10.0):C1241, _5qq(4.10.0):C1997, _5qr(4.10.0):C1468,
_5qp(4.10.0):C1729, _5qo(4.10.0):C3456/1:delGen=1, _5qu(4.10.0):C27,
_5qt(4.10.0):C30, _5qx(4.10.0):C638, _5qy(4.10.0):C1407, _5qw(4.10.0):C802,
_5r2(4.10.0):C32769/1:delGen=1, _5r3(4.10.0):C26057,
_5r4(4.10.0):C23934/1:delGen=1, _5r5(4.10.0):C24222/1:delGen=1]
packetCount=4
14:16:50,402 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [BD][recoveryExecutor-7-thread-1]:
seg=_5r4(4.10.0):C23934/1:delGen=1 segGen=7
14:16:52,774 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IFD][recoveryExecutor-7-thread-1]: delete
"_5r2_1.del"
14:16:52,774 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IFD][recoveryExecutor-7-thread-1]: 0 msec to
checkpoint
14:16:52,774 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IFD][recoveryExecutor-7-thread-1]: now
checkpoint "_4qe(4.10.0):C4312879/1nts ; isCommit = false]
14:16:52,774 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IFD][recoveryExecutor-7-thread-1]: delete
"_5r4_1.del"
14:16:52,774 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IFD][recoveryExecutor-7-thread-1]: 0 msec to
checkpoint
14:16:52,775 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [DW][recoveryExecutor-7-thread-1]:
recoveryExecutor-7-thread-1 finishFullFlush success=true
14:16:52,775 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
findMerges: 34 segments
14:16:52,777 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_554(4.10.0):C3995865/780418:delGen=23 size=3669.307 MB [skip: too
large]
14:16:52,777 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_4qe(4.10.0):C4312879/1370113:delGen=57 size=3506.254 MB [skip: too
large]
14:16:52,777 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5co(4.10.0):C871785/93995:delGen=11 size=853.668 MB
14:16:52,777 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5kb(4.10.0):C424868/49572:delGen=12 size=518.704 MB
14:16:52,777 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5hm(4.10.0):C457977/83353:delGen=12 size=470.422 MB
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_56u(4.10.0):C286775/11906:delGen=15 size=312.952 MB
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5f5(4.10.0):C116528/43621:delGen=2 size=95.529 MB
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5m7(4.10.0):C122852/54010:delGen=12 size=84.949 MB
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5p7(4.10.0):C37457/649:delGen=2 size=54.241 MB
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5of(4.10.0):C38545/5677:delGen=1 size=50.672 MB
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5qm(4.10.0):C29770/4:delGen=2 size=34.052 MB
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5o8(4.10.0):C27155/7531:delGen=1 size=31.008 MB
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5r2(4.10.0):C32769/4:delGen=2 size=27.410 MB
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5r3(4.10.0):C26057 size=23.893 MB
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5r4(4.10.0):C23934/3:delGen=2 size=22.004 MB
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5nx(4.10.0):C33236/20669:delGen=2 size=19.861 MB
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5r5(4.10.0):C24222/1:delGen=1 size=19.546 MB
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5q0(4.10.0):C13610/2625:delGen=7 size=12.480 MB
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5qv(4.10.0):C3973/1:delGen=1 size=3.402 MB
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5qo(4.10.0):C3456/2:delGen=2 size=3.147 MB
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5qq(4.10.0):C1997 size=1.781 MB [floored]
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5q2(4.10.0):C779 size=1.554 MB [floored]
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5qh(4.10.0):C1765/1:delGen=1 size=1.549 MB [floored]
14:16:52,778 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5qc(4.10.0):C1828/1:delGen=1 size=1.401 MB [floored]
14:16:52,779 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5qr(4.10.0):C1468 size=1.390 MB [floored]
14:16:52,779 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5qp(4.10.0):C1729/1:delGen=1 size=1.351 MB [floored]
14:16:52,779 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5qa(4.10.0):C967 size=1.235 MB [floored]
14:16:52,779 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5qi(4.10.0):C1241 size=1.146 MB [floored]
14:16:52,779 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5qy(4.10.0):C1407 size=1.050 MB [floored]
14:16:52,779 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5q1(4.10.0):C402/1:delGen=1 size=0.954 MB [floored]
14:16:52,779 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5qw(4.10.0):C802/1:delGen=1 size=0.821 MB [floored]
14:16:52,779 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5qx(4.10.0):C638 size=0.818 MB [floored]
14:16:52,779 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5qt(4.10.0):C30 size=0.072 MB [floored]
14:16:52,779 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
seg=_5qu(4.10.0):C27 size=0.063 MB [floored]
14:16:52,779 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
allowedSegmentCount=31 vs count=34 (eligible count=32) tooBigCount=2
14:16:52,779 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
maybe=_5co(4.10.0):C871785/93995:delGen=11
_5kb(4.10.0):C424868/49572:delGen=12 _5hm(4.10.0):C457977/83353:delGen=12
_56u(4.10.0):C286775/11906:delGen=15 _5f5(4.10.0):C116528/43621:delGen=2
_5m7(4.10.0):C122852/54010:delGen=12 _5p7(4.10.0):C37457/649:delGen=2
_5of(4.10.0):C38545/5677:delGen=1 _5qm(4.10.0):C29770/4:delGen=2
_5o8(4.10.0):C27155/7531:delGen=1 score=0.7313777596572674 skew=0.341
nonDelRatio=0.852 tooLarge=false size=2506.203 MB
.....
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
maybe=_5qr(4.10.0):C1468 _5qp(4.10.0):C1729/1:delGen=1 _5qa(4.10.0):C967
_5qi(4.10.0):C1241 _5qy(4.10.0):C1407 _5q1(4.10.0):C402/1:delGen=1
_5qw(4.10.0):C802/1:delGen=1 _5qx(4.10.0):C638 _5qt(4.10.0):C30
_5qu(4.10.0):C27 score=0.22289855634027114 skew=0.100 nonDelRatio=1.000
tooLarge=false size=8.907 MB
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]: add
merge=_5qr(4.10.0):C1468 _5qp(4.10.0):C1729/1:delGen=1 _5qa(4.10.0):C967
_5qi(4.10.0):C1241 _5qy(4.10.0):C1407 _5q1(4.10.0):C402/1:delGen=1
_5qw(4.10.0):C802/1:delGen=1 _5qx(4.10.0):C638 _5qt(4.10.0):C30
_5qu(4.10.0):C27 size=8.907 MB score=0.223 skew=0.100 nonDelRatio=1.000
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [TMP][recoveryExecutor-7-thread-1]:
allowedSegmentCount=31 vs count=34 (eligible count=22) tooBigCount=2
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]: add merge
to pendingMerges: _5qr(4.10.0):C1468 _5qp(4.10.0):C1729/1:delGen=1
_5qa(4.10.0):C967 _5qi(4.10.0):C1241 _5qy(4.10.0):C1407
_5q1(4.10.0):C402/1:delGen=1 _5qw(4.10.0):C802/1:delGen=1 _5qx(4.10.0):C638
_5qt(4.10.0):C30 _5qu(4.10.0):C27 [total 1 pending]
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]:
registerMerge merging= []
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]:
registerMerge info=_5qr(4.10.0):C1468
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]:
registerMerge info=_5qp(4.10.0):C1729/1:delGen=1
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]:
registerMerge info=_5qa(4.10.0):C967
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]:
registerMerge info=_5qi(4.10.0):C1241
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]:
registerMerge info=_5qy(4.10.0):C1407
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]:
registerMerge info=_5q1(4.10.0):C402/1:delGen=1
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]:
registerMerge info=_5qw(4.10.0):C802/1:delGen=1
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]:
registerMerge info=_5qx(4.10.0):C638
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]:
registerMerge info=_5qt(4.10.0):C30
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]:
registerMerge info=_5qu(4.10.0):C27
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [CMS][recoveryExecutor-7-thread-1]: now merge
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [CMS][recoveryExecutor-7-thread-1]: index:
_4qe(4.10.0):C4312879/1370113:delGen=57
_554(4.10.0):C3995865/780418:delGen=23 _56u(4.10.0):C286775/11906:delGen=15
_5co(4.10.0):C871785/93995:delGen=11 _5m7(4.10.0):C122852/54010:delGen=12
_5hm(4.10.0):C457977/83353:delGen=12 _5q0(4.10.0):C13610/2625:delGen=7
_5kb(4.10.0):C424868/49572:delGen=12 _5f5(4.10.0):C116528/43621:delGen=2
_5nx(4.10.0):C33236/20669:delGen=2 _5qm(4.10.0):C29770/4:delGen=2
_5o8(4.10.0):C27155/7531:delGen=1 _5of(4.10.0):C38545/5677:delGen=1
_5p7(4.10.0):C37457/649:delGen=2 _5qv(4.10.0):C3973/1:delGen=1
_5q1(4.10.0):C402/1:delGen=1 _5q2(4.10.0):C779 _5qa(4.10.0):C967
_5qc(4.10.0):C1828/1:delGen=1 _5qh(4.10.0):C1765/1:delGen=1
_5qi(4.10.0):C1241 _5qq(4.10.0):C1997 _5qr(4.10.0):C1468
_5qp(4.10.0):C1729/1:delGen=1 _5qo(4.10.0):C3456/2:delGen=2
_5qu(4.10.0):C27 _5qt(4.10.0):C30 _5qx(4.10.0):C638 _5qy(4.10.0):C1407
_5qw(4.10.0):C802/1:delGen=1 _5r2(4.10.0):C32769/4:delGen=2
_5r3(4.10.0):C26057 _5r4(4.10.0):C23934/3:delGen=2
_5r5(4.10.0):C24222/1:delGen=1
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [CMS][recoveryExecutor-7-thread-1]:
consider merge _5qr(4.10.0):C1468 _5qp(4.10.0):C1729/1:delGen=1
_5qa(4.10.0):C967 _5qi(4.10.0):C1241 _5qy(4.10.0):C1407
_5q1(4.10.0):C402/1:delGen=1 _5qw(4.10.0):C802/1:delGen=1 _5qx(4.10.0):C638
_5qt(4.10.0):C30 _5qu(4.10.0):C27
14:16:52,783 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [CMS][recoveryExecutor-7-thread-1]:
launch new thread [Lucene Merge Thread #0]
14:16:52,784 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [CMS][recoveryExecutor-7-thread-1]: set
priority of merge thread Lucene Merge Thread #0 to 6
14:16:52,784 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [CMS][recoveryExecutor-7-thread-1]: no more
merges pending; now return
14:16:52,784 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]:
startCommit(): start
14:16:52,784 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]:
startCommit index=_4qe(4.10.0):C4312879/1370113:delGen=57
_554(4.10.0):C3995865/780418:delGen=23 _56u(4.10.0):C286775/11906:delGen=15
_5co(4.10.0):C871785/93995:delGen=11 _5m7(4.10.0):C122852/54010:delGen=12
_5hm(4.10.0):C457977/83353:delGen=12 _5q0(4.10.0):C13610/2625:delGen=7
_5kb(4.10.0):C424868/49572:delGen=12 _5f5(4.10.0):C116528/43621:delGen=2
_5nx(4.10.0):C33236/20669:delGen=2 _5qm(4.10.0):C29770/4:delGen=2
_5o8(4.10.0):C27155/7531:delGen=1 _5of(4.10.0):C38545/5677:delGen=1
_5p7(4.10.0):C37457/649:delGen=2 _5qv(4.10.0):C3973/1:delGen=1
_5q1(4.10.0):C402/1:delGen=1 _5q2(4.10.0):C779 _5qa(4.10.0):C967
_5qc(4.10.0):C1828/1:delGen=1 _5qh(4.10.0):C1765/1:delGen=1
_5qi(4.10.0):C1241 _5qq(4.10.0):C1997 _5qr(4.10.0):C1468
_5qp(4.10.0):C1729/1:delGen=1 _5qo(4.10.0):C3456/2:delGen=2
_5qu(4.10.0):C27 _5qt(4.10.0):C30 _5qx(4.10.0):C638 _5qy(4.10.0):C1407
_5qw(4.10.0):C802/1:delGen=1 _5r2(4.10.0):C32769/4:delGen=2
_5r3(4.10.0):C26057 _5r4(4.10.0):C23934/3:delGen=2
_5r5(4.10.0):C24222/1:delGen=1 changeCount=28
14:16:52,784 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [CMS][Lucene Merge Thread #0]: merge thread: start
14:16:52,785 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [BD][Lucene Merge Thread #0]: applyDeletes: no deletes; skipping
14:16:52,785 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [BD][Lucene Merge Thread #0]: prune sis=segments_9t:
_4qe(4.10.0):C4312879/1370113:delGen=57
_554(4.10.0):C3995865/780418:delGen=23 _56u(4.10.0):C286775/11906:delGen=15
_5co(4.10.0):C871785/93995:delGen=11 _5m7(4.10.0):C122852/54010:delGen=12
_5hm(4.10.0):C457977/83353:delGen=12 _5q0(4.10.0):C13610/2625:delGen=7
_5kb(4.10.0):C424868/49572:delGen=12 _5f5(4.10.0):C116528/43621:delGen=2
_5nx(4.10.0):C33236/20669:delGen=2 _5qm(4.10.0):C29770/4:delGen=2
_5o8(4.10.0):C27155/7531:delGen=1 _5of(4.10.0):C38545/5677:delGen=1
_5p7(4.10.0):C37457/649:delGen=2 _5qv(4.10.0):C3973/1:delGen=1
_5q1(4.10.0):C402/1:delGen=1 _5q2(4.10.0):C779 _5qa(4.10.0):C967
_5qc(4.10.0):C1828/1:delGen=1 _5qh(4.10.0):C1765/1:delGen=1
_5qi(4.10.0):C1241 _5qq(4.10.0):C1997 _5qr(4.10.0):C1468
_5qp(4.10.0):C1729/1:delGen=1 _5qo(4.10.0):C3456/2:delGen=2
_5qu(4.10.0):C27 _5qt(4.10.0):C30 _5qx(4.10.0):C638 _5qy(4.10.0):C1407
_5qw(4.10.0):C802/1:delGen=1 _5r2(4.10.0):C32769/4:delGen=2
_5r3(4.10.0):C26057 _5r4(4.10.0):C23934/3:delGen=2
_5r5(4.10.0):C24222/1:delGen=1 minGen=10 packetCount=0
14:16:52,788 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: merge seg=_5r6 _5qr(4.10.0):C1468
_5qp(4.10.0):C1729/1:delGen=1 _5qa(4.10.0):C967 _5qi(4.10.0):C1241
_5qy(4.10.0):C1407 _5q1(4.10.0):C402/1:delGen=1
_5qw(4.10.0):C802/1:delGen=1 _5qx(4.10.0):C638 _5qt(4.10.0):C30
_5qu(4.10.0):C27
14:16:52,789 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: now merge
merge=_5qr(4.10.0):C1468 _5qp(4.10.0):C1729/1:delGen=1 _5qa(4.10.0):C967
_5qi(4.10.0):C1241 _5qy(4.10.0):C1407 _5q1(4.10.0):C402/1:delGen=1
_5qw(4.10.0):C802/1:delGen=1 _5qx(4.10.0):C638 _5qt(4.10.0):C30
_5qu(4.10.0):C27
index=_4qe(4.10.0):C4312879/1370113:delGen=57
_554(4.10.0):C3995865/780418:delGen=23 _56u(4.10.0):C286775/11906:delGen=15
_5co(4.10.0):C871785/93995:delGen=11 _5m7(4.10.0):C122852/54010:delGen=12
_5hm(4.10.0):C457977/83353:delGen=12 _5q0(4.10.0):C13610/2625:delGen=7
_5kb(4.10.0):C424868/49572:delGen=12 _5f5(4.10.0):C116528/43621:delGen=2
_5nx(4.10.0):C33236/20669:delGen=2 _5qm(4.10.0):C29770/4:delGen=2
_5o8(4.10.0):C27155/7531:delGen=1 _5of(4.10.0):C38545/5677:delGen=1
_5p7(4.10.0):C37457/649:delGen=2 _5qv(4.10.0):C3973/1:delGen=1
_5q1(4.10.0):C402/1:delGen=1 _5q2(4.10.0):C779 _5qa(4.10.0):C967
_5qc(4.10.0):C1828/1:delGen=1 _5qh(4.10.0):C1765/1:delGen=1
_5qi(4.10.0):C1241 _5qq(4.10.0):C1997 _5qr(4.10.0):C1468
_5qp(4.10.0):C1729/1:delGen=1 _5qo(4.10.0):C3456/2:delGen=2
_5qu(4.10.0):C27 _5qt(4.10.0):C30 _5qx(4.10.0):C638 _5qy(4.10.0):C1407
_5qw(4.10.0):C802/1:delGen=1 _5r2(4.10.0):C32769/4:delGen=2
_5r3(4.10.0):C26057 _5r4(4.10.0):C23934/3:delGen=2
_5r5(4.10.0):C24222/1:delGen=1
14:16:52,790 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: merging _5qr(4.10.0):C1468
_5qp(4.10.0):C1729/1:delGen=1 _5qa(4.10.0):C967 _5qi(4.10.0):C1241
_5qy(4.10.0):C1407 _5q1(4.10.0):C402/1:delGen=1
_5qw(4.10.0):C802/1:delGen=1 _5qx(4.10.0):C638 _5qt(4.10.0):C30
_5qu(4.10.0):C27
14:16:52,790 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: seg=_5qr(4.10.0):C1468 no deletes
14:16:52,790 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: seg=_5qp(4.10.0):C1729/1:delGen=1
delCount=1
14:16:52,790 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: seg=_5qa(4.10.0):C967 no deletes
14:16:52,790 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: seg=_5qi(4.10.0):C1241 no deletes
14:16:52,790 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: seg=_5qy(4.10.0):C1407 no deletes
14:16:52,790 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: seg=_5q1(4.10.0):C402/1:delGen=1
delCount=1
14:16:52,790 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: seg=_5qw(4.10.0):C802/1:delGen=1
delCount=1
14:16:52,790 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: seg=_5qx(4.10.0):C638 no deletes
14:16:52,790 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: seg=_5qt(4.10.0):C30 no deletes
14:16:52,790 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: seg=_5qu(4.10.0):C27 no deletes
14:16:52,792 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [SM][Lucene Merge Thread #0]: merge store matchedCount=10 vs 10
14:16:52,929 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [SM][Lucene Merge Thread #0]: 137 msec to merge stored fields
[8708 docs]
14:16:53,012 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]: done all
syncs: [_5p7_Lucene41_0.pos, _5qr.si, _5kb_Lucene41_0.tim, _5q1.fdt,
_5kb_Lucene41_0.tip, _5qp.fnm, _5o8_1.del, _5qa_Lucene41_0.doc, _5qq.fnm,
_5qr.fnm, _5co_b.del, _5qh.fdx, _5qm.fdx, _5qh.fdt, _5kb_c.del, _5r5.fnm,
_554.fdx, _5qm.fdt, _5r3_Lucene41_0.doc, _4qe.fdt, _56u_Lucene41_0.doc,
_554.fdt, _5qi.fdt, _5q2_Lucene41_0.doc, _4qe.fdx, _5qa.si, _5qi.fdx, _
5qy.si, _56u.fdx, _5qv_Lucene41_0.tip, _5qh.si, _5qw_Lucene41_0.pos,
_5hm_Lucene41_0.pos, _5nx.si, _5co_Lucene41_0.pos, _5q1.fdx, _5qt.fdx,
_5qt.fdt, _5r5.si, _5co.fdt, _5nx.fnm, _5qv_Lucene41_0.tim, _5co.fdx,
_5qh_Lucene41_0.doc, _5kb.fdx, _5qh_1.del, _5qm_Lucene41_0.tim, _56u.fdt,
_5r4_2.del, _5r3_Lucene41_0.tip, _5hm.fdt, _5qv_1.del, _5qm_Lucene41_0.tip,
_5qr_Lucene41_0.doc, _5kb.fdt, _5of_Lucene41_0.tip, _5hm.fdx,
_5r3_Lucene41_0.tim, _5of_Lucene41_0.tim, _56u_f.del, _5qy_Lucene41_0.doc,
_5r4_Lucene41_0.pos, _5qq.si, _5qt_Lucene41_0.doc, _5qq_Lucene41_0.pos,
_5qa.fnm, _5qv.si, _5r2.fnm, _5qo_2.del, _5p7.fdt, _5r3.fnm,
_5p7_Lucene41_0.doc, _5r4.fdt, _5qo.si, _5p7.fdx, _5qa_Lucene41_0.tim, _
5qp.si, _5kb.si, _5r4.fdx, _5qp_Lucene41_0.tip, _4qe.si,
_5qp_Lucene41_0.tim, _5qa_Lucene41_0.tip, _4qe_1l.del, _5qp_1.del,
_5qw_1.del, _5qm_2.del, _5m7_Lucene41_0.tim, _5qw.si, _5m7_Lucene41_0.tip, _
56u.si, _5of_Lucene41_0.doc, _5of.si, _5of.fnm, _4qe_Lucene41_0.tip,
_5qh_Lucene41_0.pos, _5qi.si, _4qe_Lucene41_0.tim, _5qc.fdx,
_5r2_Lucene41_0.pos, _5qm.fnm, _5qc.fdt, _5qx_Lucene41_0.pos,
_5qo_Lucene41_0.doc, _5q0.fnm, _5qv.fdx, _5qi_Lucene41_0.pos,
_5p7_Lucene41_0.tim, _5qv.fdt, _5f5.si, _5p7_Lucene41_0.tip, _5q2.fdt, _
5o8.si, _5qm_Lucene41_0.doc, _5qc_Lucene41_0.tim, _5f5_Lucene41_0.tim,
_5f5_Lucene41_0.tip, _5qc_Lucene41_0.tip, _5qx.fdx, _554_Lucene41_0.doc,
_5q2_Lucene41_0.pos, _5r4_Lucene41_0.tim, _5qx.fdt, _5q1_Lucene41_0.pos,
_5qp_Lucene41_0.doc, _5qm.si, _56u.fnm, _5q0_Lucene41_0.pos,
_5r4_Lucene41_0.tip, _5qq.fdx, _5qr_Lucene41_0.pos, _56u_Lucene41_0.pos,
_5r2_Lucene41_0.doc, _5qw_Lucene41_0.doc, _5r5_Lucene41_0.tim,
_5r5_Lucene41_0.tip, _554.fnm, _5qi.fnm, _56u_Lucene41_0.tim,
_5qo_Lucene41_0.pos, _56u_Lucene41_0.tip, _5f5.fnm, _5qq.fdt, _5q0_7.del,
_5m7.fnm, _5qo.fnm, _5qu.si, _5q2.fdx, _5qt_Lucene41_0.tip,
_5qw_Lucene41_0.tip, _5qt_Lucene41_0.tim, _5qc.si, _5hm.si, _5m7.si, _5r2.si,
_5f5_Lucene41_0.pos, _5qy_Lucene41_0.tip, _5nx_Lucene41_0.tim,
_5r2_Lucene41_0.tip, _5qm_Lucene41_0.pos, _5qq_Lucene41_0.tim, _5co.si,
_5r2.fdt, _5r2_Lucene41_0.tim, _5f5_2.del, _5qq_Lucene41_0.tip,
_5qy_Lucene41_0.tim, _5nx_Lucene41_0.tip, _5o8_Lucene41_0.doc, _5r3.fdt,
_5qv_Lucene41_0.pos, _5q1_Lucene41_0.doc, _5qo_Lucene41_0.tip, _5qx.fnm,
_5qo_Lucene41_0.tim, _5co.fnm, _5qu.fdt, _5qu.fdx, _5r5.fdx, _554_n.del,
_4qe_Lucene41_0.pos, _5q1_Lucene41_0.tip, _5f5_Lucene41_0.doc, _5r5.fdt,
_5qw_Lucene41_0.tim, _5m7_c.del, _5qv.fnm, _5q1_Lucene41_0.tim, _5kb.fnm, _
5q2.si, _5qy.fnm, _5kb_Lucene41_0.pos, _5qx_Lucene41_0.doc, _5r4.fnm,
_5qu_Lucene41_0.pos, _5r5_Lucene41_0.doc, _554_Lucene41_0.pos,
_5qc_Lucene41_0.doc, _5hm_Lucene41_0.doc, _5p7.fnm, _5qt.si, _5p7_2.del,
_5qi_Lucene41_0.doc, _5r2_2.del, _5r3.fdx, _5o8.fdx, _5q1.fnm, _5nx.fdt,
_4qe.fnm, _5nx.fdx, _5q1.si, _5r3_Lucene41_0.pos, _5qa.fdt, _5r2.fdx,
_5o8.fdt, _5qa_Lucene41_0.pos, _5qc_1.del, _5qw.fnm, _5m7_Lucene41_0.doc,
_5qa.fdx, _5hm.fnm, _554.si, _5r4.si, _5qy_Lucene41_0.pos,
_5qr_Lucene41_0.tim, _5qr_Lucene41_0.tip, _5qy.fdx, _5nx_Lucene41_0.pos,
_5m7.fdt, _5kb_Lucene41_0.doc, _5m7.fdx, _554_Lucene41_0.tip, _5qc.fnm,
_5o8_Lucene41_0.tim, _5co_Lucene41_0.doc, _554_Lucene41_0.tim, _5qy.fdt, _
5qx.si, _5o8_Lucene41_0.tip, _5qu.fnm, _5nx_Lucene41_0.doc, _5q2.fnm,
_5o8_Lucene41_0.pos, _5qt_Lucene41_0.pos, _5qt.fnm, _5qh_Lucene41_0.tip,
_5qh_Lucene41_0.tim, _5q2_Lucene41_0.tip, _5q2_Lucene41_0.tim,
_5q0_Lucene41_0.doc, _5hm_c.del, _5r5_1.del, _5o8.fnm, _5qu_Lucene41_0.doc,
_5q0_Lucene41_0.tip, _5hm_Lucene41_0.tip, _5r5_Lucene41_0.pos, _5qo.fdx,
_5f5.fdt, _5q0_Lucene41_0.tim, _5qr.fdx, _5qu_Lucene41_0.tim, _5p7.si,
_5q1_1.del, _5of_1.del, _5qp.fdt, _5q0.fdx, _5q0.si, _5r4_Lucene41_0.doc,
_5of.fdx, _4qe_Lucene41_0.doc, _5qh.fnm, _5of.fdt, _5of_Lucene41_0.pos,
_5f5.fdx, _5m7_Lucene41_0.pos, _5r3.si, _5qw.fdt, _5qx_Lucene41_0.tim,
_5qx_Lucene41_0.tip, _5nx_2.del, _5qv_Lucene41_0.doc, _5qw.fdx, _5q0.fdt,
_5co_Lucene41_0.tim, _5qq_Lucene41_0.doc, _5qp.fdx, _5qu_Lucene41_0.tip,
_5qr.fdt, _5qi_Lucene41_0.tip, _5qp_Lucene41_0.pos, _5hm_Lucene41_0.tim,
_5qi_Lucene41_0.tim, _5qo.fdt, _5co_Lucene41_0.tip, _5qc_Lucene41_0.pos]
14:16:53,013 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]: commit:
pendingCommit != null
14:16:53,015 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]: commit:
wrote segments file "segments_9u"
14:16:53,015 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IFD][recoveryExecutor-7-thread-1]: now
checkpoint "_4qe(4.10.0):C4312879/1370113:delGen=57
_554(4.10.0):C3995865/780418:delGen=23 _56u(4.10.0):C286775/11906:delGen=15
_5co(4.10.0):C871785/93995:delGen=11 _5m7(4.10.0):C122852/54010:delGen=12
_5hm(4.10.0):C457977/83353:delGen=12 _5q0(4.10.0):C13610/2625:delGen=7
_5kb(4.10.0):C424868/49572:delGen=12 _5f5(4.10.0):C116528/43621:delGen=2
_5nx(4.10.0):C33236/20669:delGen=2 _5qm(4.10.0):C29770/4:delGen=2
_5o8(4.10.0):C27155/7531:delGen=1 _5of(4.10.0):C38545/5677:delGen=1
_5p7(4.10.0):C37457/649:delGen=2 _5qv(4.10.0):C3973/1:delGen=1
_5q1(4.10.0):C402/1:delGen=1 _5q2(4.10.0):C779 _5qa(4.10.0):C967
_5qc(4.10.0):C1828/1:delGen=1 _5qh(4.10.0):C1765/1:delGen=1
_5qi(4.10.0):C1241 _5qq(4.10.0):C1997 _5qr(4.10.0):C1468
_5qp(4.10.0):C1729/1:delGen=1 _5qo(4.10.0):C3456/2:delGen=2
_5qu(4.10.0):C27 _5qt(4.10.0):C30 _5qx(4.10.0):C638 _5qy(4.10.0):C1407
_5qw(4.10.0):C802/1:delGen=1 _5r2(4.10.0):C32769/4:delGen=2
_5r3(4.10.0):C26057 _5r4(4.10.0):C23934/3:delGen=2
_5r5(4.10.0):C24222/1:delGen=1" [34 segments ; isCommit = true]
14:16:53,015 INFO [org.apache.solr.core.SolrCore]
(recoveryExecutor-7-thread-1) SolrDeletionPolicy.onCommit: commits: num=2
commit{dir=NRTCachingDirectory(MMapDirectory@/opt/solr/solrnodes/solrnode1/search1_shard7_replica4/data/index.20150126140904697
lockFactory=NativeFSLockFactory@/opt/solr/solrnodes/solrnode1/search1_shard7_replica4/data/index.20150126140904697;
maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_9t,generation=353}
commit{dir=NRTCachingDirectory(MMapDirectory@/opt/solr/solrnodes/solrnode1/search1_shard7_replica4/data/index.20150126140904697
lockFactory=NativeFSLockFactory@/opt/solr/solrnodes/solrnode1/search1_shard7_replica4/data/index.20150126140904697;
maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_9u,generation=354}
14:16:53,016 INFO [org.apache.solr.core.SolrCore]
(recoveryExecutor-7-thread-1) newest commit generation = 354
14:16:53,016 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IFD][recoveryExecutor-7-thread-1]:
deleteCommits: now decRef commit "segments_9t"
14:16:53,016 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IFD][recoveryExecutor-7-thread-1]: delete
"segments_9t"
14:16:53,016 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IFD][recoveryExecutor-7-thread-1]: 1 msec to
checkpoint
14:16:53,016 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]: commit:
took 3733.0 msec
14:16:53,016 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]: commit:
done
14:16:53,017 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [DW][recoveryExecutor-7-thread-1]:
anyChanges? numDocsInRam=0 deletes=false hasTickets:false
pendingChangesInFullFlush: false
14:16:53,017 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]:
nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes:
false
14:16:53,017 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]: flush at
getReader
14:16:53,017 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [DW][recoveryExecutor-7-thread-1]:
startFullFlush
14:16:53,017 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [DW][recoveryExecutor-7-thread-1]:
anyChanges? numDocsInRam=0 deletes=false hasTickets:false
pendingChangesInFullFlush: false
14:16:53,017 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]: apply all
deletes during flush
14:16:53,017 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [BD][recoveryExecutor-7-thread-1]:
applyDeletes: no deletes; skipping
14:16:53,017 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [BD][recoveryExecutor-7-thread-1]: prune
sis=segments_9u: _4qe(4.10.0):C4312879/1370113:delGen=57
_554(4.10.0):C3995865/780418:delGen=23 _56u(4.10.0):C286775/11906:delGen=15
_5co(4.10.0):C871785/93995:delGen=11 _5m7(4.10.0):C122852/54010:delGen=12
_5hm(4.10.0):C457977/83353:delGen=12 _5q0(4.10.0):C13610/2625:delGen=7
_5kb(4.10.0):C424868/49572:delGen=12 _5f5(4.10.0):C116528/43621:delGen=2
_5nx(4.10.0):C33236/20669:delGen=2 _5qm(4.10.0):C29770/4:delGen=2
_5o8(4.10.0):C27155/7531:delGen=1 _5of(4.10.0):C38545/5677:delGen=1
_5p7(4.10.0):C37457/649:delGen=2 _5qv(4.10.0):C3973/1:delGen=1
_5q1(4.10.0):C402/1:delGen=1 _5q2(4.10.0):C779 _5qa(4.10.0):C967
_5qc(4.10.0):C1828/1:delGen=1 _5qh(4.10.0):C1765/1:delGen=1
_5qi(4.10.0):C1241 _5qq(4.10.0):C1997 _5qr(4.10.0):C1468
_5qp(4.10.0):C1729/1:delGen=1 _5qo(4.10.0):C3456/2:delGen=2
_5qu(4.10.0):C27 _5qt(4.10.0):C30 _5qx(4.10.0):C638 _5qy(4.10.0):C1407
_5qw(4.10.0):C802/1:delGen=1 _5r2(4.10.0):C32769/4:delGen=2
_5r3(4.10.0):C26057 _5r4(4.10.0):C23934/3:delGen=2
_5r5(4.10.0):C24222/1:delGen=1 minGen=10 packetCount=0
14:16:53,026 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]: return
reader version=16082 reader=StandardDirectoryReader(segments_9u:16082:nrt
_4qe(4.10.0):C4312879/1370113:delGen=57
_554(4.10.0):C3995865/780418:delGen=23 _56u(4.10.0):C286775/11906:delGen=15
_5co(4.10.0):C871785/93995:delGen=11 _5m7(4.10.0):C122852/54010:delGen=12
_5hm(4.10.0):C457977/83353:delGen=12 _5q0(4.10.0):C13610/2625:delGen=7
_5kb(4.10.0):C424868/49572:delGen=12 _5f5(4.10.0):C116528/43621:delGen=2
_5nx(4.10.0):C33236/20669:delGen=2 _5qm(4.10.0):C29770/4:delGen=2
_5o8(4.10.0):C27155/7531:delGen=1 _5of(4.10.0):C38545/5677:delGen=1
_5p7(4.10.0):C37457/649:delGen=2 _5qv(4.10.0):C3973/1:delGen=1
_5q1(4.10.0):C402/1:delGen=1 _5q2(4.10.0):C779 _5qa(4.10.0):C967
_5qc(4.10.0):C1828/1:delGen=1 _5qh(4.10.0):C1765/1:delGen=1
_5qi(4.10.0):C1241 _5qq(4.10.0):C1997 _5qr(4.10.0):C1468
_5qp(4.10.0):C1729/1:delGen=1 _5qo(4.10.0):C3456/2:delGen=2
_5qu(4.10.0):C27 _5qt(4.10.0):C30 _5qx(4.10.0):C638 _5qy(4.10.0):C1407
_5qw(4.10.0):C802/1:delGen=1 _5r2(4.10.0):C32769/4:delGen=2
_5r3(4.10.0):C26057 _5r4(4.10.0):C23934/3:delGen=2
_5r5(4.10.0):C24222/1:delGen=1)
14:16:53,026 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [DW][recoveryExecutor-7-thread-1]:
recoveryExecutor-7-thread-1 finishFullFlush success=true
14:16:53,026 INFO [org.apache.solr.update.LoggingInfoStream]
(recoveryExecutor-7-thread-1) [IW][recoveryExecutor-7-thread-1]: getReader
took 9 msec
14:16:53,026 INFO [org.apache.solr.search.SolrIndexSearcher]
(recoveryExecutor-7-thread-1) Opening Searcher@dbe17f9[search1_shard7_replica4]
main
14:16:53,120 INFO [org.apache.solr.update.UpdateHandler]
(recoveryExecutor-7-thread-1) end_commit_flush
==> gc.20150126-135638.log <==
1214.654: [GC1214.654: [ParNew: 974509K->56784K(996800K), 0.0150450 secs]
1519683K->603424K(1995752K), 0.0152330 secs] [Times: user=0.14 sys=0.00,
real=0.02 secs]
==> server.log <==
14:16:53,406 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [SM][Lucene Merge Thread #0]: 477 msec to merge postings [8708
docs]
14:16:53,406 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [SM][Lucene Merge Thread #0]: 0 msec to merge doc values [8708
docs]
14:16:53,407 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: merge codec=Lucene410
docCount=8708; merged segment has no vectors; no norms; no docValues; prox;
freqs
14:16:53,407 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: merged segment size=7.623 MB vs
estimate=8.906 MB
14:16:53,408 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: commitMerge: _5qr(4.10.0):C1468
_5qp(4.10.0):C1729/1:delGen=1 _5qa(4.10.0):C967 _5qi(4.10.0):C1241
_5qy(4.10.0):C1407 _5q1(4.10.0):C402/1:delGen=1
_5qw(4.10.0):C802/1:delGen=1 _5qx(4.10.0):C638 _5qt(4.10.0):C30
_5qu(4.10.0):C27 index=_4qe(4.10.0):C4312879/1370113:delGen=57
_554(4.10.0):C3995865/780418:delGen=23 _56u(4.10.0):C286775/11906:delGen=15
_5co(4.10.0):C871785/93995:delGen=11 _5m7(4.10.0):C122852/54010:delGen=12
_5hm(4.10.0):C457977/83353:delGen=12 _5q0(4.10.0):C13610/2625:delGen=7
_5kb(4.10.0):C424868/49572:delGen=12 _5f5(4.10.0):C116528/43621:delGen=2
_5nx(4.10.0):C33236/20669:delGen=2 _5qm(4.10.0):C29770/4:delGen=2
_5o8(4.10.0):C27155/7531:delGen=1 _5of(4.10.0):C38545/5677:delGen=1
_5p7(4.10.0):C37457/649:delGen=2 _5qv(4.10.0):C3973/1:delGen=1
_5q1(4.10.0):C402/1:delGen=1 _5q2(4.10.0):C779 _5qa(4.10.0):C967
_5qc(4.10.0):C1828/1:delGen=1 _5qh(4.10.0):C1765/1:delGen=1
_5qi(4.10.0):C1241 _5qq(4.10.0):C1997 _5qr(4.10.0):C1468
_5qp(4.10.0):C1729/1:delGen=1 _5qo(4.10.0):C3456/2:delGen=2
_5qu(4.10.0):C27 _5qt(4.10.0):C30 _5qx(4.10.0):C638 _5qy(4.10.0):C1407
_5qw(4.10.0):C802/1:delGen=1 _5r2(4.10.0):C32769/4:delGen=2
_5r3(4.10.0):C26057 _5r4(4.10.0):C23934/3:delGen=2
_5r5(4.10.0):C24222/1:delGen=1
14:16:53,408 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: commitMergeDeletes
_5qr(4.10.0):C1468 _5qp(4.10.0):C1729/1:delGen=1 _5qa(4.10.0):C967
_5qi(4.10.0):C1241 _5qy(4.10.0):C1407 _5q1(4.10.0):C402/1:delGen=1
_5qw(4.10.0):C802/1:delGen=1 _5qx(4.10.0):C638 _5qt(4.10.0):C30
_5qu(4.10.0):C27
14:16:53,408 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: no new deletes or field updates
since merge started
14:16:53,408 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IFD][Lucene Merge Thread #0]: now checkpoint
"_4qe(4.10.0):C4312879/1370113:delGen=57
_554(4.10.0):C3995865/780418:delGen=23 _56u(4.10.0):C286775/11906:delGen=15
_5co(4.10.0):C871785/93995:delGen=11 _5m7(4.10.0):C122852/54010:delGen=12
_5hm(4.10.0):C457977/83353:delGen=12 _5q0(4.10.0):C13610/2625:delGen=7
_5kb(4.10.0):C424868/49572:delGen=12 _5f5(4.10.0):C116528/43621:delGen=2
_5nx(4.10.0):C33236/20669:delGen=2 _5qm(4.10.0):C29770/4:delGen=2
_5o8(4.10.0):C27155/7531:delGen=1 _5of(4.10.0):C38545/5677:delGen=1
_5p7(4.10.0):C37457/649:delGen=2 _5qv(4.10.0):C3973/1:delGen=1
_5r6(4.10.0):C8708 _5q2(4.10.0):C779 _5qc(4.10.0):C1828/1:delGen=1
_5qh(4.10.0):C1765/1:delGen=1 _5qq(4.10.0):C1997
_5qo(4.10.0):C3456/2:delGen=2 _5r2(4.10.0):C32769/4:delGen=2
_5r3(4.10.0):C26057 _5r4(4.10.0):C23934/3:delGen=2
_5r5(4.10.0):C24222/1:delGen=1" [25 segments ; isCommit = false]
14:16:53,408 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IFD][Lucene Merge Thread #0]: 0 msec to checkpoint
14:16:53,408 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: after commitMerge:
_4qe(4.10.0):C4312879/1370113:delGen=57
_554(4.10.0):C3995865/780418:delGen=23 _56u(4.10.0):C286775/11906:delGen=15
_5co(4.10.0):C871785/93995:delGen=11 _5m7(4.10.0):C122852/54010:delGen=12
_5hm(4.10.0):C457977/83353:delGen=12 _5q0(4.10.0):C13610/2625:delGen=7
_5kb(4.10.0):C424868/49572:delGen=12 _5f5(4.10.0):C116528/43621:delGen=2
_5nx(4.10.0):C33236/20669:delGen=2 _5qm(4.10.0):C29770/4:delGen=2
_5o8(4.10.0):C27155/7531:delGen=1 _5of(4.10.0):C38545/5677:delGen=1
_5p7(4.10.0):C37457/649:delGen=2 _5qv(4.10.0):C3973/1:delGen=1
_5r6(4.10.0):C8708 _5q2(4.10.0):C779 _5qc(4.10.0):C1828/1:delGen=1
_5qh(4.10.0):C1765/1:delGen=1 _5qq(4.10.0):C1997
_5qo(4.10.0):C3456/2:delGen=2 _5r2(4.10.0):C32769/4:delGen=2
_5r3(4.10.0):C26057 _5r4(4.10.0):C23934/3:delGen=2
_5r5(4.10.0):C24222/1:delGen=1
14:16:53,408 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]: findMerges: 25 segments
14:16:53,409 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_554(4.10.0):C3995865/780418:delGen=23 size=3669.307 MB [skip: too
large]
14:16:53,409 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_4qe(4.10.0):C4312879/1370113:delGen=57 size=3506.254 MB [skip: too
large]
14:16:53,409 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_5co(4.10.0):C871785/93995:delGen=11 size=853.668 MB
14:16:53,409 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_5kb(4.10.0):C424868/49572:delGen=12 size=518.704 MB
14:16:53,409 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_5hm(4.10.0):C457977/83353:delGen=12 size=470.422 MB
14:16:53,409 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_56u(4.10.0):C286775/11906:delGen=15 size=312.952 MB
14:16:53,409 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_5f5(4.10.0):C116528/43621:delGen=2 size=95.529 MB
14:16:53,409 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_5m7(4.10.0):C122852/54010:delGen=12 size=84.949 MB
14:16:53,409 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_5p7(4.10.0):C37457/649:delGen=2 size=54.241 MB
14:16:53,409 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_5of(4.10.0):C38545/5677:delGen=1 size=50.672 MB
14:16:53,409 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_5qm(4.10.0):C29770/4:delGen=2 size=34.052 MB
14:16:53,409 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_5o8(4.10.0):C27155/7531:delGen=1 size=31.008 MB
14:16:53,409 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_5r2(4.10.0):C32769/4:delGen=2 size=27.410 MB
14:16:53,409 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]: seg=_5r3(4.10.0):C26057
size=23.893 MB
14:16:53,409 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_5r4(4.10.0):C23934/3:delGen=2 size=22.004 MB
14:16:53,409 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_5nx(4.10.0):C33236/20669:delGen=2 size=19.861 MB
14:16:53,410 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_5r5(4.10.0):C24222/1:delGen=1 size=19.546 MB
14:16:53,410 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_5q0(4.10.0):C13610/2625:delGen=7 size=12.480 MB
14:16:53,410 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]: seg=_5r6(4.10.0):C8708
size=7.622 MB
14:16:53,410 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_5qv(4.10.0):C3973/1:delGen=1 size=3.402 MB
14:16:53,410 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_5qo(4.10.0):C3456/2:delGen=2 size=3.147 MB
14:16:53,410 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]: seg=_5qq(4.10.0):C1997
size=1.781 MB [floored]
14:16:53,410 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]: seg=_5q2(4.10.0):C779
size=1.554 MB [floored]
14:16:53,410 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_5qh(4.10.0):C1765/1:delGen=1 size=1.549 MB [floored]
14:16:53,410 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]:
seg=_5qc(4.10.0):C1828/1:delGen=1 size=1.401 MB [floored]
14:16:53,410 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [TMP][Lucene Merge Thread #0]: allowedSegmentCount=31 vs
count=25 (eligible count=23) tooBigCount=2
14:16:53,410 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [IW][Lucene Merge Thread #0]: merge time 625 msec for 8708 docs
14:16:53,410 INFO [org.apache.solr.update.LoggingInfoStream] (Lucene Merge
Thread #0) [CMS][Lucene Merge Thread #0]: merge thread: done
==> gc.20150126-135638.log <==
1217.747: [GC1217.747: [ParNew: 942864K->33781K(996800K), 0.0409520 secs]
1489504K->580420K(1995752K), 0.0411310 secs] [Times: user=0.25 sys=0.00,
real=0.04 secs]
==> server.log <==
14:16:58,363 INFO [org.apache.solr.core.SolrCore]
(searcherExecutor-6-thread-1) QuerySenderListener sending requests to
Searcher@dbe17f9[search1_shard7_replica4]
main{StandardDirectoryReader(segments_9u:16082:nrt
_4qe(4.10.0):C4312879/1370113:delGen=57
_554(4.10.0):C3995865/780418:delGen=23 _56u(4.10.0):C286775/11906:delGen=15
_5co(4.10.0):C871785/93995:delGen=11 _5m7(4.10.0):C122852/54010:delGen=12
_5hm(4.10.0):C457977/83353:delGen=12 _5q0(4.10.0):C13610/2625:delGen=7
_5kb(4.10.0):C424868/49572:delGen=12 _5f5(4.10.0):C116528/43621:delGen=2
_5nx(4.10.0):C33236/20669:delGen=2 _5qm(4.10.0):C29770/4:delGen=2
_5o8(4.10.0):C27155/7531:delGen=1 _5of(4.10.0):C38545/5677:delGen=1
_5p7(4.10.0):C37457/649:delGen=2 _5qv(4.10.0):C3973/1:delGen=1
_5q1(4.10.0):C402/1:delGen=1 _5q2(4.10.0):C779 _5qa(4.10.0):C967
_5qc(4.10.0):C1828/1:delGen=1 _5qh(4.10.0):C1765/1:delGen=1
_5qi(4.10.0):C1241 _5qq(4.10.0):C1997 _5qr(4.10.0):C1468
_5qp(4.10.0):C1729/1:delGen=1 _5qo(4.10.0):C3456/2:delGen=2
_5qu(4.10.0):C27 _5qt(4.10.0):C30 _5qx(4.10.0):C638 _5qy(4.10.0):C1407
_5qw(4.10.0):C802/1:delGen=1 _5r2(4.10.0):C32769/4:delGen=2
_5r3(4.10.0):C26057 _5r4(4.10.0):C23934/3:delGen=2
_5r5(4.10.0):C24222/1:delGen=1)}
14:16:58,363 INFO [org.apache.solr.core.SolrCore]
(searcherExecutor-6-thread-1) QuerySenderListener done.
14:16:58,365 INFO [org.apache.solr.core.SolrCore]
(searcherExecutor-6-thread-1) [search1_shard7_replica4] Registered new
searcher Searcher@dbe17f9[search1_shard7_replica4]
main{StandardDirectoryReader(segments_9u:16082:nrt
_4qe(4.10.0):C4312879/1370113:delGen=57
_554(4.10.0):C3995865/780418:delGen=23 _56u(4.10.0):C286775/11906:delGen=15
_5co(4.10.0):C871785/93995:delGen=11 _5m7(4.10.0):C122852/54010:delGen=12
_5hm(4.10.0):C457977/83353:delGen=12 _5q0(4.10.0):C13610/2625:delGen=7
_5kb(4.10.0):C424868/49572:delGen=12 _5f5(4.10.0):C116528/43621:delGen=2
_5nx(4.10.0):C33236/20669:delGen=2 _5qm(4.10.0):C29770/4:delGen=2
_5o8(4.10.0):C27155/7531:delGen=1 _5of(4.10.0):C38545/5677:delGen=1
_5p7(4.10.0):C37457/649:delGen=2 _5qv(4.10.0):C3973/1:delGen=1
_5q1(4.10.0):C402/1:delGen=1 _5q2(4.10.0):C779 _5qa(4.10.0):C967
_5qc(4.10.0):C1828/1:delGen=1 _5qh(4.10.0):C1765/1:delGen=1
_5qi(4.10.0):C1241 _5qq(4.10.0):C1997 _5qr(4.10.0):C1468
_5qp(4.10.0):C1729/1:delGen=1 _5qo(4.10.0):C3456/2:delGen=2
_5qu(4.10.0):C27 _5qt(4.10.0):C30 _5qx(4.10.0):C638 _5qy(4.10.0):C1407
_5qw(4.10.0):C802/1:delGen=1 _5r2(4.10.0):C32769/4:delGen=2
_5r3(4.10.0):C26057 _5r4(4.10.0):C23934/3:delGen=2
_5r5(4.10.0):C24222/1:delGen=1)}
14:16:58,367 INFO [org.apache.solr.update.LoggingInfoStream]
(searcherExecutor-6-thread-1) [IFD][searcherExecutor-6-thread-1]: delete
"_4qe_1k.del"
14:16:58,367 INFO [org.apache.solr.update.LoggingInfoStream]
(searcherExecutor-6-thread-1) [IFD][searcherExecutor-6-thread-1]: delete
"_5p7_1.del"
14:16:58,367 INFO [org.apache.solr.update.LoggingInfoStream]
(searcherExecutor-6-thread-1) [IFD][searcherExecutor-6-thread-1]: delete
"_5nx_1.del"
14:16:58,367 INFO [org.apache.solr.update.LoggingInfoStream]
(searcherExecutor-6-thread-1) [IFD][searcherExecutor-6-thread-1]: delete
"_5co_a.del"
14:16:58,367 INFO [org.apache.solr.update.LoggingInfoStream]
(searcherExecutor-6-thread-1) [IFD][searcherExecutor-6-thread-1]: delete
"_5q0_6.del"
14:16:58,367 INFO [org.apache.solr.update.LoggingInfoStream]
(searcherExecutor-6-thread-1) [
On Sun, Jan 25, 2015 at 9:53 PM, Erick Erickson <erickerick...@gmail.com>
wrote:
> Ah, OK. Whew! because I was wondering how you were running at _all_ if all
> the memory was allocated to the JVM ;)..
>
> What is your Zookeeper timeout? The original default was 15 seconds and
> this
> has caused problems like this. Here's the scenario:
> You send a bunch of docs at the server, and eventually you hit a
> stop-the-world
> GC that takes longer than the Zookeeper timeout. So ZK thinks the node is
> down
> and initiates recovery. Eventually, you hit this on all the replicas.
>
> Sometimes I've seen situations where the answer is giving a bit more memory
> to the JVM, say 2-4G in your case. The theory here (and this is a shot in
> the
> dark) that your peak JVM requirements are close to your 12G, so the garbage
> collection spends enormous amounts of time collecting a small bit of
> memory,
> runs for some fraction of a second and does it again. Adding more to the
> JVMs
> memory allows the parallel collections to work without so many
> stop-the-world
> GC pauses.
>
> So what I'd do is turn on GC logging (probably on the replicas) and look
> for
> very long GC pauses. Mark Miller put together a blog here:
> https://lucidworks.com/blog/garbage-collection-bootcamp-1-0/
>
> See the "getting a view into garbage collection". The smoking gun here
> is if you see full GC pauses that are longer than the ZK timeout.
>
> 90M docs in 4 hours across 10 shards is only 625/sec or so per shard. I've
> seen
> sustained indexing rates significantly above this, YMMV or course, a lot
> depends
> on the size of the docs.
>
> What version of Solr BTW? And when you say you fire a bunch of indexers,
> I'm
> assuming these are SolrJ clients and use CloudSolrServer?
>
> Best,
> Erick
>
>
> On Sun, Jan 25, 2015 at 4:10 PM, Vijay Sekhri <sekhrivi...@gmail.com>
> wrote:
>
> > Thank you for the reply Eric.
> > I am sorry I had wrong information posted. I posted our DEV env
> > configuration by mistake.
> > After double checking our stress and Prod Beta env where we have found
> the
> > original issue, I found all the searchers have around 50 GB of RAM
> > available and two instances of JVM running (2 different ports). Both
> > instances have 12 GB allocated. The rest 26 GB is available for the OS.
> 1st
> > instance on a host has search1 collection (live collection) and the 2nd
> > instance on the same host has search2 collection (for full indexing ).
> >
> > There is plenty room for OS related tasks. Our issue is not in anyway
> > related to OS starving as shown from our dashboards.
> > We have been through
> >
> >
> https://lucidworks.com/blog/understanding-transaction-logs-softcommit-and-commit-in-sorlcloud/
> > a lot of times but we have two modes of operation
> > a) 1st collection (Live traffic) - heavy searches and medium indexing
> > b) 2nd collection (Not serving traffic) - very heavy indexing, no
> searches
> >
> > When our indexing finishes we swap the alias for these collection . So
> > essentially we need to have a configuration that can support both the use
> > cases together. We have tried a lot of different configuration options
> and
> > none of them seems to work. My suspicion is that solr cloud is unable to
> > keep up with the updates at the rate we are sending while it is trying to
> > be consistent with all the replicas.
> >
> >
> > On Sun, Jan 25, 2015 at 5:30 PM, Erick Erickson <erickerick...@gmail.com
> >
> > wrote:
> >
> > > Shawn directed you over here to the user list, but I see this note on
> > > SOLR-7030:
> > > "All our searchers have 12 GB of RAM available and have quad core
> > Intel(R)
> > > Xeon(R) CPU X5570 @ 2.93GHz. There is only one java process running i.e
> > > jboss and solr in it . All 12 GB is available as heap for the java
> > > process..."
> > >
> > > So you have 12G physical memory and have allocated 12G to the Java
> > process?
> > > This is an anti-pattern. If that's
> > > the case, your operating system is being starved for memory, probably
> > > hitting a state where it spends all of its
> > > time in stop-the-world garbage collection, eventually it doesn't
> respond
> > to
> > > Zookeeper's ping so Zookeeper
> > > thinks the node is down and puts it into recovery. Where it spends a
> lot
> > of
> > > time doing... essentially nothing.
> > >
> > > About the hard and soft commits: I suspect these are entirely
> unrelated,
> > > but here's a blog on what they do, you
> > > should pick the configuration that supports your use case (i.e. how
> much
> > > latency can you stand between indexing
> > > and being able to search?).
> > >
> > >
> > >
> >
> https://lucidworks.com/blog/understanding-transaction-logs-softcommit-and-commit-in-sorlcloud/
> > >
> > > Here's one very good reason you shouldn't starve your op system by
> > > allocating all the physical memory to the JVM:
> > >
> http://blog.thetaphi.de/2012/07/use-lucenes-mmapdirectory-on-64bit.html
> > >
> > >
> > > But your biggest problem is that you have far too much of your physical
> > > memory allocated to the JVM. This
> > > will cause you endless problems, you just need more physical memory on
> > > those boxes. It's _possible_ you could
> > > get by with less memory for the JVM, counterintuitive as it seems try
> 8G
> > or
> > > maybe even 6G. At some point
> > > you'll hit OOM errors, but that'll give you a lower limit on what the
> JVM
> > > needs.
> > >
> > > Unless I've mis-interpreted what you've written, though, I doubt you'll
> > get
> > > stable with that much memory allocated
> > > to the JVM.
> > >
> > > Best,
> > > Erick
> > >
> > >
> > >
> > > On Sun, Jan 25, 2015 at 1:02 PM, Vijay Sekhri <sekhrivi...@gmail.com>
> > > wrote:
> > >
> > > > We have a cluster of solr cloud server with 10 shards and 4 replicas
> in
> > > > each shard in our stress environment. In our prod environment we will
> > > have
> > > > 10 shards and 15 replicas in each shard. Our current commit settings
> > are
> > > as
> > > > follows
> > > >
> > > > * <autoSoftCommit>*
> > > > * <maxDocs>500000</maxDocs>*
> > > > * <maxTime>180000</maxTime>*
> > > > * </autoSoftCommit>*
> > > > * <autoCommit>*
> > > > * <maxDocs>2000000</maxDocs>*
> > > > * <maxTime>180000</maxTime>*
> > > > * <openSearcher>false</openSearcher>*
> > > > * </autoCommit>*
> > > >
> > > >
> > > > We indexed roughly 90 Million docs. We have two different ways to
> index
> > > > documents a) Full indexing. It takes 4 hours to index 90 Million docs
> > and
> > > > the rate of docs coming to the searcher is around 6000 per second b)
> > > > Incremental indexing. It takes an hour to indexed delta changes.
> > Roughly
> > > > there are 3 million changes and rate of docs coming to the searchers
> is
> > > > 2500
> > > > per second
> > > >
> > > > We have two collections search1 and search2. When we do full
> indexing ,
> > > we
> > > > do it in search2 collection while search1 is serving live traffic.
> > After
> > > it
> > > > finishes we swap the collection using aliases so that the search2
> > > > collection serves live traffic while search1 becomes available for
> next
> > > > full indexing run. When we do incremental indexing we do it in the
> > > search1
> > > > collection which is serving live traffic.
> > > >
> > > > All our searchers have 12 GB of RAM available and have quad core
> > Intel(R)
> > > > Xeon(R) CPU X5570 @ 2.93GHz. There is only one java process running
> i.e
> > > > jboss and solr in it . All 12 GB is available as heap for the java
> > > > process. We have observed that the heap memory of the java process
> > > average
> > > > around 8 - 10 GB. All searchers have final index size of 9 GB. So in
> > > total
> > > > there are 9X10 (shards) = 90GB worth of index files.
> > > >
> > > > We have observed the following issue when we trigger indexing . In
> > about
> > > > 10 minutes after we trigger indexing on 14 parallel hosts, the
> replicas
> > > > goes in to recovery mode. This happens to all the shards . In about
> 20
> > > > minutes more and more replicas start going into recovery mode. After
> > > about
> > > > half an hour all replicas except the leader are in recovery mode. We
> > > cannot
> > > > throttle the indexing load as that will increase our overall indexing
> > > time.
> > > > So to overcome this issue, we remove all the replicas before we
> trigger
> > > the
> > > > indexing and then add them back after the indexing finishes.
> > > >
> > > > We observe the same behavior of replicas going into recovery when we
> do
> > > > incremental indexing. We cannot remove replicas during our
> incremental
> > > > indexing because it is also serving live traffic. We tried to
> throttle
> > > our
> > > > indexing speed , however the cluster still goes into recovery .
> > > >
> > > > If we leave the cluster as it , when the indexing finishes , it
> > > eventually
> > > > recovers after a while. As it is serving live traffic we cannot have
> > > these
> > > > replicas go into recovery mode because it degrades the search
> > performance
> > > > also , our tests have shown.
> > > >
> > > > We have tried different commit settings like below
> > > >
> > > > a) No auto soft commit, no auto hard commit and a commit triggered at
> > the
> > > > end of indexing b) No auto soft commit, yes auto hard commit and a
> > commit
> > > > in the end of indexing
> > > > c) Yes auto soft commit , no auto hard commit
> > > > d) Yes auto soft commit , yes auto hard commit
> > > > e) Different frequency setting for commits for above. Please NOTE
> that
> > we
> > > > have tried 15 minute soft commit setting and 30 minutes hard commit
> > > > settings. Same time settings for both, 30 minute soft commit and an
> > hour
> > > > hard commit setting
> > > >
> > > > Unfortunately all the above yields the same behavior . The replicas
> > still
> > > > goes in recovery We have increased the zookeeper timeout from 30
> > seconds
> > > to
> > > > 5 minutes and the problem persists. Is there any setting that would
> fix
> > > > this issue ?
> > > >
> > > > --
> > > > *********************************************
> > > > Vijay Sekhri
> > > > *********************************************
> > > >
> > >
> >
> >
> >
> > --
> > *********************************************
> > Vijay Sekhri
> > *********************************************
> >
>
--
*********************************************
Vijay Sekhri
*********************************************
