You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/08/11 00:50:50 UTC

[JENKINS] Lucene-Solr-4.x-Windows (64bit/jdk1.8.0_11) - Build # 4150 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/4150/
Java: 64bit/jdk1.8.0_11 -XX:-UseCompressedOops -XX:+UseParallelGC

1 tests failed.
FAILED:  junit.framework.TestSuite.org.apache.solr.client.solrj.embedded.LargeVolumeEmbeddedTest

Error Message:
Could not remove the following files (in the order of attempts):    C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\tlog\tlog.0000000000000000004    C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\tlog    C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001    C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001 

Stack Trace:
java.io.IOException: Could not remove the following files (in the order of attempts):
   C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\tlog\tlog.0000000000000000004
   C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\tlog
   C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001
   C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001

	at __randomizedtesting.SeedInfo.seed([1A2F9D6E994B6802]:0)
	at org.apache.lucene.util.TestUtil.rm(TestUtil.java:117)
	at org.apache.lucene.util.LuceneTestCase$TemporaryFilesCleanupRule.afterAlways(LuceneTestCase.java:2675)
	at com.carrotsearch.randomizedtesting.rules.TestRuleAdapter$1.afterAlways(TestRuleAdapter.java:31)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:43)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at java.lang.Thread.run(Thread.java:745)




Build Log:
[...truncated 12720 lines...]
   [junit4] Suite: org.apache.solr.client.solrj.embedded.LargeVolumeEmbeddedTest
   [junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001
   [junit4]   2> 93171 T146 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
   [junit4]   2> 93171 T146 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 93172 T146 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\'
   [junit4]   2> 93230 T146 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
   [junit4]   2> 93231 T146 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/extraction/lib (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\contrib\extraction\lib).
   [junit4]   2> 93232 T146 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\dist).
   [junit4]   2> 93232 T146 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/clustering/lib/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\contrib\clustering\lib).
   [junit4]   2> 93232 T146 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\dist).
   [junit4]   2> 93232 T146 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/langid/lib/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\contrib\langid\lib).
   [junit4]   2> 93236 T146 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\dist).
   [junit4]   2> 93236 T146 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/velocity/lib (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\contrib\velocity\lib).
   [junit4]   2> 93236 T146 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\dist).
   [junit4]   2> 93266 T146 oasu.SolrIndexConfig.<init> IndexWriter infoStream solr logging is enabled
   [junit4]   2> 93269 T146 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
   [junit4]   2> 93311 T146 oasc.SolrConfig.<init> Loaded SolrConfig: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr/collection1/conf/solrconfig.xml
   [junit4]   2> 93312 T146 oass.IndexSchema.readSchema Reading Solr Schema from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr/collection1/conf/schema.xml
   [junit4]   2> 93325 T146 oass.IndexSchema.readSchema [null] Schema name=example
   [junit4]   2> 93723 T146 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 93736 T146 oasr.RestManager$Registry.registerManagedResource Registered ManagedResource impl org.apache.solr.rest.schema.analysis.ManagedWordSetResource for path /schema/analysis/stopwords/english
   [junit4]   2> 93736 T146 oasr.RestManager$Registry.registerManagedResource Registered ManagedResource impl org.apache.solr.rest.schema.analysis.ManagedSynonymFilterFactory$SynonymManager for path /schema/analysis/synonyms/english
   [junit4]   2> 93751 T146 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 93756 T146 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 93791 T146 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 93791 T146 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr
   [junit4]   2> 93791 T146 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\'
   [junit4]   2> 93824 T146 oasc.CoreContainer.<init> New CoreContainer 262031549
   [junit4]   2> 93824 T146 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\]
   [junit4]   2> 93825 T146 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 93825 T146 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 93825 T146 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 93825 T146 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 93825 T146 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 93825 T146 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 93825 T146 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 93825 T146 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 93825 T146 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 93836 T146 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=30000&connTimeout=30000&retry=false
   [junit4]   2> 93840 T146 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 93840 T146 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 93840 T146 oasc.CoreContainer.load Host Name: 
   [junit4]   2> 93863 T147 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1/'
   [junit4]   2> 93897 T147 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
   [junit4]   2> 93897 T147 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/extraction/lib (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\contrib\extraction\lib).
   [junit4]   2> 93897 T147 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\dist).
   [junit4]   2> 93897 T147 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/clustering/lib/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\contrib\clustering\lib).
   [junit4]   2> 93897 T147 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\dist).
   [junit4]   2> 93900 T147 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/langid/lib/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\contrib\langid\lib).
   [junit4]   2> 93900 T147 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\dist).
   [junit4]   2> 93900 T147 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/velocity/lib (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\contrib\velocity\lib).
   [junit4]   2> 93900 T147 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\dist).
   [junit4]   2> 93927 T147 oasu.SolrIndexConfig.<init> IndexWriter infoStream solr logging is enabled
   [junit4]   2> 93930 T147 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
   [junit4]   2> 93973 T147 oasc.SolrConfig.<init> Loaded SolrConfig: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr/collection1/conf/solrconfig.xml
   [junit4]   2> 93975 T147 oass.IndexSchema.readSchema Reading Solr Schema from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr/collection1/conf/schema.xml
   [junit4]   2> 93993 T147 oass.IndexSchema.readSchema [collection1] Schema name=example
   [junit4]   2> 94265 T147 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 94269 T147 oasr.RestManager$Registry.registerManagedResource Registered ManagedResource impl org.apache.solr.rest.schema.analysis.ManagedWordSetResource for path /schema/analysis/stopwords/english
   [junit4]   2> 94269 T147 oasr.RestManager$Registry.registerManagedResource Registered ManagedResource impl org.apache.solr.rest.schema.analysis.ManagedSynonymFilterFactory$SynonymManager for path /schema/analysis/synonyms/english
   [junit4]   2> 94286 T147 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 94290 T147 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 94322 T147 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1/
   [junit4]   2> 94322 T147 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 94322 T147 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1/, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\
   [junit4]   2> 94322 T147 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
   [junit4]   2> 94323 T147 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
   [junit4]   2> 94323 T147 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
   [junit4]   2> 94323 T147 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\
   [junit4]   2> 94323 T147 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\index/
   [junit4]   2> 94323 T147 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\index' doesn't exist. Creating new index...
   [junit4]   2> 94324 T147 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\index
   [junit4]   2> 94328 T147 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-105-thread-1]: init: current segments file is "null"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@739226ab
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-105-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-105-thread-1]: 0 msec to checkpoint
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: init: create=true
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: 
   [junit4]   2> 	dir=MockDirectoryWrapper(RAMDirectory@3c963ec lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\index)
   [junit4]   2> 	index=
   [junit4]   2> 	version=4.10-SNAPSHOT
   [junit4]   2> 	matchVersion=LUCENE_4_10
   [junit4]   2> 	analyzer=null
   [junit4]   2> 	ramBufferSizeMB=100.0
   [junit4]   2> 	maxBufferedDocs=-1
   [junit4]   2> 	maxBufferedDeleteTerms=-1
   [junit4]   2> 	mergedSegmentWarmer=null
   [junit4]   2> 	readerTermsIndexDivisor=1
   [junit4]   2> 	termIndexInterval=32
   [junit4]   2> 	delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
   [junit4]   2> 	commit=null
   [junit4]   2> 	openMode=CREATE
   [junit4]   2> 	similarity=org.apache.lucene.search.similarities.DefaultSimilarity
   [junit4]   2> 	mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
   [junit4]   2> 	default WRITE_LOCK_TIMEOUT=1000
   [junit4]   2> 	writeLockTimeout=1000
   [junit4]   2> 	codec=Lucene49
   [junit4]   2> 	infoStream=org.apache.solr.update.LoggingInfoStream
   [junit4]   2> 	mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 	indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@3b8ced36
   [junit4]   2> 	readerPooling=false
   [junit4]   2> 	perThreadHardLimitMB=1945
   [junit4]   2> 	useCompoundFile=false
   [junit4]   2> 	checkIntegrityAtMerge=false
   [junit4]   2> 	writer=org.apache.lucene.util.SetOnce@11d525f4
   [junit4]   2> 	
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: now flush at close waitForMerges=true
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]:   start flush: applyAllDeletes=true
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]:   index before flush 
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-105-thread-1]: startFullFlush
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-105-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-105-thread-1]: coreLoadExecutor-105-thread-1 finishFullFlush success=true
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: apply all deletes during flush
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-105-thread-1]: prune sis=null:  minGen=9223372036854775807 packetCount=0
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-105-thread-1]: now merge
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-105-thread-1]:   index: 
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-105-thread-1]:   no more merges pending; now return
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: waitForMerges
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: waitForMerges done
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: now call final commit()
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: commit: start
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: commit: enter lock
   [junit4]   2> 94329 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: commit: now prepare
   [junit4]   2> 94332 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: prepareCommit: flush
   [junit4]   2> 94332 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]:   index before flush 
   [junit4]   2> 94332 T147 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-105-thread-1]: startFullFlush
   [junit4]   2> 94332 T147 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-105-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 94332 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: apply all deletes during flush
   [junit4]   2> 94332 T147 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-105-thread-1]: prune sis=null:  minGen=9223372036854775807 packetCount=0
   [junit4]   2> 94332 T147 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-105-thread-1]: coreLoadExecutor-105-thread-1 finishFullFlush success=true
   [junit4]   2> 94332 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: startCommit(): start
   [junit4]   2> 94332 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: startCommit index= changeCount=1
   [junit4]   2> 94332 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: done all syncs: []
   [junit4]   2> 94332 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: commit: pendingCommit != null
   [junit4]   2> 94332 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: commit: wrote segments file "segments_1"
   [junit4]   2> 94335 T147 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-105-thread-1]: now checkpoint "" [0 segments ; isCommit = true]
   [junit4]   2> 94335 T147 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@3c963ec lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\index),segFN=segments_1,generation=1}
   [junit4]   2> 94335 T147 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 94336 T147 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-105-thread-1]: 0 msec to checkpoint
   [junit4]   2> 94336 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: commit: took 5.1 msec
   [junit4]   2> 94336 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: commit: done
   [junit4]   2> 94336 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: at close: 
   [junit4]   2> 94336 T147 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
   [junit4]   2> 94336 T147 oasc.SolrCore.initWriters adding lazy queryResponseWriter: solr.VelocityResponseWriter
   [junit4]   2> 94336 T147 oasc.SolrCore.initWriters created velocity: solr.VelocityResponseWriter
   [junit4]   2> 94337 T147 oasc.SolrCore.initWriters created xslt: solr.XSLTResponseWriter
   [junit4]   2> 94337 T147 oasr.XSLTResponseWriter.init xsltCacheLifetimeSeconds=5
   [junit4]   2> 94345 T147 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 94347 T147 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 94348 T147 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 94348 T147 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 94348 T147 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 94348 T147 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
   [junit4]   2> 94348 T147 oasc.RequestHandlers.initHandlersFromConfig created /query: solr.SearchHandler
   [junit4]   2> 94349 T147 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 94349 T147 oasc.RequestHandlers.initHandlersFromConfig created /browse: solr.SearchHandler
   [junit4]   2> 94349 T147 oasc.RequestHandlers.initHandlersFromConfig WARN Multiple requestHandler registered to the same name: /update ignoring: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 94349 T147 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 94349 T147 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
   [junit4]   2> 94349 T147 oasc.RequestHandlers.initHandlersFromConfig created /update/extract: solr.extraction.ExtractingRequestHandler
   [junit4]   2> 94349 T147 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.FieldAnalysisRequestHandler
   [junit4]   2> 94349 T147 oasc.RequestHandlers.initHandlersFromConfig created /analysis/field: solr.FieldAnalysisRequestHandler
   [junit4]   2> 94349 T147 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
   [junit4]   2> 94349 T147 oasc.RequestHandlers.initHandlersFromConfig created /analysis/document: solr.DocumentAnalysisRequestHandler
   [junit4]   2> 94352 T147 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
   [junit4]   2> 94379 T147 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
   [junit4]   2> 94379 T147 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
   [junit4]   2> 94380 T147 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 94380 T147 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 94380 T147 oasc.RequestHandlers.initHandlersFromConfig created /spell: solr.SearchHandler
   [junit4]   2> 94380 T147 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 94380 T147 oasc.RequestHandlers.initHandlersFromConfig created /suggest: solr.SearchHandler
   [junit4]   2> 94380 T147 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 94380 T147 oasc.RequestHandlers.initHandlersFromConfig created /tvrh: solr.SearchHandler
   [junit4]   2> 94380 T147 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 94380 T147 oasc.RequestHandlers.initHandlersFromConfig created /terms: solr.SearchHandler
   [junit4]   2> 94380 T147 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 94380 T147 oasc.RequestHandlers.initHandlersFromConfig created /elevate: solr.SearchHandler
   [junit4]   2> 94384 T147 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 94388 T147 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 94389 T147 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 94390 T147 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 94394 T147 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 94396 T147 oasu.CommitTracker.<init> Hard AutoCommit: if uncommited for 15000ms; 
   [junit4]   2> 94396 T147 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 94399 T147 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-105-thread-1]: init: current segments file is "segments_1"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@739226ab
   [junit4]   2> 94399 T147 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-105-thread-1]: init: load commit "segments_1"
   [junit4]   2> 94399 T147 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@3c963ec lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\index),segFN=segments_1,generation=1}
   [junit4]   2> 94399 T147 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 94400 T147 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-105-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 94400 T147 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-105-thread-1]: 0 msec to checkpoint
   [junit4]   2> 94400 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: init: create=false
   [junit4]   2> 94400 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: 
   [junit4]   2> 	dir=MockDirectoryWrapper(RAMDirectory@3c963ec lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\index)
   [junit4]   2> 	index=
   [junit4]   2> 	version=4.10-SNAPSHOT
   [junit4]   2> 	matchVersion=LUCENE_4_10
   [junit4]   2> 	analyzer=null
   [junit4]   2> 	ramBufferSizeMB=100.0
   [junit4]   2> 	maxBufferedDocs=-1
   [junit4]   2> 	maxBufferedDeleteTerms=-1
   [junit4]   2> 	mergedSegmentWarmer=null
   [junit4]   2> 	readerTermsIndexDivisor=1
   [junit4]   2> 	termIndexInterval=32
   [junit4]   2> 	delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
   [junit4]   2> 	commit=null
   [junit4]   2> 	openMode=APPEND
   [junit4]   2> 	similarity=org.apache.lucene.search.similarities.DefaultSimilarity
   [junit4]   2> 	mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
   [junit4]   2> 	default WRITE_LOCK_TIMEOUT=1000
   [junit4]   2> 	writeLockTimeout=1000
   [junit4]   2> 	codec=Lucene49
   [junit4]   2> 	infoStream=org.apache.solr.update.LoggingInfoStream
   [junit4]   2> 	mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 	indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@5705ffd9
   [junit4]   2> 	readerPooling=false
   [junit4]   2> 	perThreadHardLimitMB=1945
   [junit4]   2> 	useCompoundFile=false
   [junit4]   2> 	checkIntegrityAtMerge=false
   [junit4]   2> 	writer=org.apache.lucene.util.SetOnce@403f2a33
   [junit4]   2> 	
   [junit4]   2> 94400 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: flush at getReader
   [junit4]   2> 94400 T147 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-105-thread-1]: startFullFlush
   [junit4]   2> 94401 T147 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-105-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 94401 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: apply all deletes during flush
   [junit4]   2> 94401 T147 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-105-thread-1]: prune sis=segments_1:  minGen=9223372036854775807 packetCount=0
   [junit4]   2> 94401 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
   [junit4]   2> 94401 T147 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-105-thread-1]: coreLoadExecutor-105-thread-1 finishFullFlush success=true
   [junit4]   2> 94401 T147 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-105-thread-1]: getReader took 1 msec
   [junit4]   2> 94401 T147 oass.SolrIndexSearcher.<init> Opening Searcher@1541ba95[collection1] main
   [junit4]   2> 94404 T147 oasr.ManagedResourceStorage.newStorageIO WARN Cannot write to config directory C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\conf; switching to use InMemory storage instead.
   [junit4]   2> 94404 T147 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 94404 T147 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
   [junit4]   2> 94404 T147 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
   [junit4]   2> 94404 T147 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using InMemoryStorage
   [junit4]   2> 94404 T147 oasr.RestManager.init Initializing 2 registered ManagedResources
   [junit4]   2> 94404 T147 oasr.ManagedResourceStorage.load Reading _schema_analysis_stopwords_english.json using InMemoryStorage
   [junit4]   2> 94405 T147 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /schema/analysis/stopwords/english
   [junit4]   2> 94405 T147 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _schema_analysis_stopwords_english.json using InMemoryStorage
   [junit4]   2> 94405 T147 oasrsa.ManagedWordSetResource.onManagedDataLoadedFromStorage Loaded 0 words for /schema/analysis/stopwords/english
   [junit4]   2> 94405 T147 oasr.ManagedResource.notifyObserversDuringInit Notified 1 observers of /schema/analysis/stopwords/english
   [junit4]   2> 94405 T147 oasr.ManagedResourceStorage.load Reading _schema_analysis_synonyms_english.json using InMemoryStorage
   [junit4]   2> 94405 T147 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /schema/analysis/synonyms/english
   [junit4]   2> 94405 T147 oasrsa.ManagedSynonymFilterFactory$SynonymManager.onManagedDataLoadedFromStorage Loaded 0 synonym mappings for /schema/analysis/synonyms/english
   [junit4]   2> 94405 T147 oasr.ManagedResource.notifyObserversDuringInit Notified 1 observers of /schema/analysis/synonyms/english
   [junit4]   2> 94405 T147 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 94407 T147 oass.DirectSolrSpellChecker.init init: {name=default,field=text,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
   [junit4]   2> 94407 T147 oashc.SpellCheckComponent.inform No queryConverter defined, using default converter
   [junit4]   2> 94407 T147 oashc.SuggestComponent.inform Initializing SuggestComponent
   [junit4]   2> 94407 T147 oasss.SolrSuggester.init init: {name=mySuggester,lookupImpl=FuzzyLookupFactory,dictionaryImpl=DocumentDictionaryFactory,field=cat,weightField=price,suggestAnalyzerFieldType=string}
   [junit4]   2> 94408 T147 oasss.SolrSuggester.init Dictionary loaded with params: {name=mySuggester,lookupImpl=FuzzyLookupFactory,dictionaryImpl=DocumentDictionaryFactory,field=cat,weightField=price,suggestAnalyzerFieldType=string}
   [junit4]   2> 94408 T147 oashc.QueryElevationComponent.inform Loading QueryElevation from: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\conf\elevate.xml
   [junit4]   2> 94429 T147 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 94429 T147 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 94430 T148 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1541ba95[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> ASYNC  NEW_CORE C17 name=collection1 org.apache.solr.core.SolrCore@6542d4ec
   [junit4]   2> 94431 T148 C17 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+firstSearcher+warming+in+solrconfig.xml&distrib=false&event=firstSearcher} hits=0 status=0 QTime=1 
   [junit4]   2> 94431 T148 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 94431 T148 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
   [junit4]   2> 94431 T148 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
   [junit4]   2> 94431 T148 oashc.SuggestComponent$SuggesterListener.newSearcher Loading suggester index for: mySuggester
   [junit4]   2> 94431 T148 oasss.SolrSuggester.reload reload()
   [junit4]   2> 94431 T148 oasss.SolrSuggester.build build()
   [junit4]   2> 94438 T148 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1541ba95[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 94447 T146 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 94451 T146 oas.SolrTestCaseJ4.setUp ###Starting testMultiThreaded
   [junit4]   2> 94455 T146 C17 oasu.LoggingInfoStream.message [DW][TEST-LargeVolumeEmbeddedTest.testMultiThreaded-seed#[1A2F9D6E994B6802]]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 94455 T146 C17 oasu.LoggingInfoStream.message [IW][TEST-LargeVolumeEmbeddedTest.testMultiThreaded-seed#[1A2F9D6E994B6802]]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
   [junit4]   2> 94455 T146 C17 oasu.LoggingInfoStream.message [DW][TEST-LargeVolumeEmbeddedTest.testMultiThreaded-seed#[1A2F9D6E994B6802]]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 94455 T146 C17 oasu.LoggingInfoStream.message [IW][TEST-LargeVolumeEmbeddedTest.testMultiThreaded-seed#[1A2F9D6E994B6802]]: flush at getReader
   [junit4]   2> 94455 T146 C17 oasu.LoggingInfoStream.message [DW][TEST-LargeVolumeEmbeddedTest.testMultiThreaded-seed#[1A2F9D6E994B6802]]: startFullFlush
   [junit4]   2> 94455 T146 C17 oasu.LoggingInfoStream.message [DW][TEST-LargeVolumeEmbeddedTest.testMultiThreaded-seed#[1A2F9D6E994B6802]]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 94455 T146 C17 oasu.LoggingInfoStream.message [DW][TEST-LargeVolumeEmbeddedTest.testMultiThreaded-seed#[1A2F9D6E994B6802]]: TEST-LargeVolumeEmbeddedTest.testMultiThreaded-seed#[1A2F9D6E994B6802]: flush naked frozen global deletes
   [junit4]   2> 94458 T146 C17 oasu.LoggingInfoStream.message [BD][TEST-LargeVolumeEmbeddedTest.testMultiThreaded-seed#[1A2F9D6E994B6802]]: push deletes  1 deleted queries bytesUsed=84 delGen=2 packetCount=1 totBytesUsed=84
   [junit4]   2> 94458 T146 C17 oasu.LoggingInfoStream.message [DW][TEST-LargeVolumeEmbeddedTest.testMultiThreaded-seed#[1A2F9D6E994B6802]]: flush: push buffered updates:  1 deleted queries bytesUsed=84
   [junit4]   2> 94458 T146 C17 oasu.LoggingInfoStream.message [IW][TEST-LargeVolumeEmbeddedTest.testMultiThreaded-seed#[1A2F9D6E994B6802]]: apply all deletes during flush
   [junit4]   2> 94458 T146 C17 oasu.LoggingInfoStream.message [BD][TEST-LargeVolumeEmbeddedTest.testMultiThreaded-seed#[1A2F9D6E994B6802]]: prune sis=segments_1:  minGen=9223372036854775807 packetCount=1
   [junit4]   2> 94458 T146 C17 oasu.LoggingInfoStream.message [BD][TEST-LargeVolumeEmbeddedTest.testMultiThreaded-seed#[1A2F9D6E994B6802]]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 94458 T146 C17 oasu.LoggingInfoStream.message [IW][TEST-LargeVolumeEmbeddedTest.testMultiThreaded-seed#[1A2F9D6E994B6802]]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
   [junit4]   2> 94458 T146 C17 oasu.LoggingInfoStream.message [DW][TEST-LargeVolumeEmbeddedTest.testMultiThreaded-seed#[1A2F9D6E994B6802]]: TEST-LargeVolumeEmbeddedTest.testMultiThreaded-seed#[1A2F9D6E994B6802] finishFullFlush success=true
   [junit4]   2> 94458 T146 C17 oasu.LoggingInfoStream.message [IW][TEST-LargeVolumeEmbeddedTest.testMultiThreaded-seed#[1A2F9D6E994B6802]]: getReader took 3 msec
   [junit4]   2> 94460 T146 C17 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {deleteByQuery=*:* (-1476091712046628864)} 0 9
   [junit4]   2> 94464 T146 oascs.LargeVolumeTestBase.testMultiThreaded Started thread: 0
   [junit4]   2> 94467 T146 oascs.LargeVolumeTestBase.testMultiThreaded Started thread: 1
   [junit4]   2> 94468 T146 oascs.LargeVolumeTestBase.testMultiThreaded Started thread: 2
   [junit4]   2> 94469 T146 oascs.LargeVolumeTestBase.testMultiThreaded Started thread: 3
   [junit4]   2> 94469 T146 oascs.LargeVolumeTestBase.testMultiThreaded Started thread: 4
   [junit4]   2> 94490 T152 C17 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[T1:0 (1476091712067600384), T1:1 (1476091712078086149), T1:2 (1476091712079134720), T1:3 (1476091712079134721), T1:4 (1476091712079134722), T1:5 (1476091712079134723), T1:6 (1476091712079134724), T1:7 (1476091712079134725), T1:8 (1476091712079134726), T1:9 (1476091712079134727), ... (100 adds)]} 0 19
   [junit4]   2> 94491 T152 C17 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 94491 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: commit: start
   [junit4]   2> 94491 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: commit: enter lock
   [junit4]   2> 94491 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: commit: now prepare
   [junit4]   2> 94491 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: prepareCommit: flush
   [junit4]   2> 94491 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]:   index before flush 
   [junit4]   2> 94491 T152 C17 oasu.LoggingInfoStream.message [DW][DocThread-1]: startFullFlush
   [junit4]   2> 94491 T152 C17 oasu.LoggingInfoStream.message [DW][DocThread-1]: anyChanges? numDocsInRam=121 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 94491 T152 C17 oasu.LoggingInfoStream.message [DWFC][DocThread-1]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 20 deleted terms (unique count=20) bytesUsed=4641, segment=_0, aborting=false, numDocsInRAM=11, deleteQueue=DWDQ: [ generation: 2 ]]
   [junit4]   2> 94494 T155 C17 oasu.LoggingInfoStream.message [DWFC][DocThread-4]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_2, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 2 ]]
   [junit4]   2> 94497 T153 C17 oasu.LoggingInfoStream.message [DWFC][DocThread-2]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_1, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 2 ]]
   [junit4]   2> 94497 T151 C17 oasu.LoggingInfoStream.message [DWFC][DocThread-0]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 99 deleted terms (unique count=99) bytesUsed=23058, segment=_3, aborting=false, numDocsInRAM=100, deleteQueue=DWDQ: [ generation: 2 ]]
   [junit4]   2> 94538 T155 C17 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[T4:0 (1476091712066551808), T4:1 (1476091712090669056), T4:2 (1476091712099057665), T4:3 (1476091712099057666), T4:4 (1476091712099057667), T4:5 (1476091712099057668), T4:6 (1476091712099057669), T4:7 (1476091712099057670), T4:8 (1476091712099057671), T4:9 (1476091712099057672), ... (100 adds)]} 0 67
   [junit4]   2> 94542 T151 C17 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[T0:0 (1476091712060260352), T0:1 (1476091712074940416), T0:2 (1476091712075988992), T0:3 (1476091712075988993), T0:4 (1476091712075988994), T0:5 (1476091712075988995), T0:6 (1476091712075988996), T0:7 (1476091712075988997), T0:8 (1476091712077037568), T0:9 (1476091712077037569), ... (100 adds)]} 0 77
   [junit4]   2> 94545 T153 C17 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[T2:0 (1476091712064454656), T2:1 (1476091712093814784), T2:2 (1476091712129466368), T2:3 (1476091712129466369), T2:4 (1476091712129466370), T2:5 (1476091712129466371), T2:6 (1476091712129466372), T2:7 (1476091712129466373), T2:8 (1476091712129466374), T2:9 (1476091712129466375), ... (100 adds)]} 0 77
   [junit4]   2> 94545 T152 C17 oasu.LoggingInfoStream.message [DWFC][DocThread-1]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 9 deleted terms (unique count=9) bytesUsed=2089, segment=_4, aborting=false, numDocsInRAM=10, deleteQueue=DWDQ: [ generation: 2 ]]
   [junit4]   2> 94547 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flush postings as segment _0 numDocs=11
   [junit4]   2> 94548 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: new segment has 0 deleted docs
   [junit4]   2> 94548 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 94548 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushedFiles=[_0_Lucene41_0.tip, _0_Lucene41_0.doc, _0_Lucene41_0.tim, _0.nvd, _0.fdx, _0.fdt, _0_Lucene41_0.pos, _0.nvm, _0.fnm]
   [junit4]   2> 94548 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushed codec=Lucene49
   [junit4]   2> 94548 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushed: segment=_0 ramUsed=0.099 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=7,446.311
   [junit4]   2> 94548 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flush postings as segment _2 numDocs=1
   [junit4]   2> 94548 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: new segment has 0 deleted docs
   [junit4]   2> 94548 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 94548 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushedFiles=[_2.nvd, _2_Lucene41_0.tip, _2.fdt, _2_Lucene41_0.doc, _2_Lucene41_0.tim, _2.nvm, _2.fnm, _2.fdx, _2_Lucene41_0.pos]
   [junit4]   2> 94548 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushed codec=Lucene49
   [junit4]   2> 94551 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushed: segment=_2 ramUsed=0.071 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=874.542
   [junit4]   2> 94551 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flush postings as segment _1 numDocs=1
   [junit4]   2> 94552 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: new segment has 0 deleted docs
   [junit4]   2> 94552 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 94552 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushedFiles=[_1.nvd, _1_Lucene41_0.tip, _1.fdx, _1_Lucene41_0.doc, _1_Lucene41_0.tim, _1.nvm, _1.fnm, _1.fdt, _1_Lucene41_0.pos]
   [junit4]   2> 94552 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushed codec=Lucene49
   [junit4]   2> 94552 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushed: segment=_1 ramUsed=0.071 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=874.542
   [junit4]   2> 94552 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flush postings as segment _3 numDocs=100
   [junit4]   2> 94557 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: new segment has 0 deleted docs
   [junit4]   2> 94557 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 94557 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushedFiles=[_3.fdx, _3_Lucene41_0.pos, _3.nvd, _3_Lucene41_0.doc, _3_Lucene41_0.tim, _3_Lucene41_0.tip, _3.nvm, _3.fnm, _3.fdt]
   [junit4]   2> 94557 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushed codec=Lucene49
   [junit4]   2> 94557 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushed: segment=_3 ramUsed=0.099 MB newFlushedSize(includes docstores)=0.004 MB docs/MB=27,932.232
   [junit4]   2> 94558 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flush postings as segment _4 numDocs=10
   [junit4]   2> 94558 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: new segment has 0 deleted docs
   [junit4]   2> 94558 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 94558 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushedFiles=[_4.fdt, _4_Lucene41_0.pos, _4.nvm, _4.fnm, _4_Lucene41_0.tip, _4_Lucene41_0.doc, _4_Lucene41_0.tim, _4.nvd, _4.fdx]
   [junit4]   2> 94558 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushed codec=Lucene49
   [junit4]   2> 94558 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushed: segment=_4 ramUsed=0.098 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=6,889.461
   [junit4]   2> 94561 T152 C17 oasu.LoggingInfoStream.message [DW][DocThread-1]: publishFlushedSegment seg-private updates=null
   [junit4]   2> 94561 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: publishFlushedSegment
   [junit4]   2> 94561 T152 C17 oasu.LoggingInfoStream.message [BD][DocThread-1]: push deletes  123 deleted terms (unique count=123) bytesUsed=1072 delGen=4 packetCount=1 totBytesUsed=1072
   [junit4]   2> 94561 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: publish sets newSegment delGen=5 seg=_0(4.10):C11
   [junit4]   2> 94561 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: now checkpoint "_0(4.10):C11" [1 segments ; isCommit = false]
   [junit4]   2> 94561 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: 0 msec to checkpoint
   [junit4]   2> 94562 T152 C17 oasu.LoggingInfoStream.message [DW][DocThread-1]: publishFlushedSegment seg-private updates=null
   [junit4]   2> 94562 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: publishFlushedSegment
   [junit4]   2> 94562 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: publish sets newSegment delGen=6 seg=_2(4.10):C1
   [junit4]   2> 94562 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: now checkpoint "_0(4.10):C11 _2(4.10):C1" [2 segments ; isCommit = false]
   [junit4]   2> 94562 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: 0 msec to checkpoint
   [junit4]   2> 94562 T152 C17 oasu.LoggingInfoStream.message [DW][DocThread-1]: publishFlushedSegment seg-private updates=null
   [junit4]   2> 94562 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: publishFlushedSegment
   [junit4]   2> 94562 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: publish sets newSegment delGen=7 seg=_1(4.10):C1
   [junit4]   2> 94564 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: now checkpoint "_0(4.10):C11 _2(4.10):C1 _1(4.10):C1" [3 segments ; isCommit = false]
   [junit4]   2> 94564 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: 0 msec to checkpoint
   [junit4]   2> 94564 T152 C17 oasu.LoggingInfoStream.message [DW][DocThread-1]: publishFlushedSegment seg-private updates=null
   [junit4]   2> 94564 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: publishFlushedSegment
   [junit4]   2> 94564 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: publish sets newSegment delGen=8 seg=_3(4.10):C100
   [junit4]   2> 94565 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: now checkpoint "_0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100" [4 segments ; isCommit = false]
   [junit4]   2> 94565 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: 0 msec to checkpoint
   [junit4]   2> 94565 T152 C17 oasu.LoggingInfoStream.message [DW][DocThread-1]: publishFlushedSegment seg-private updates=null
   [junit4]   2> 94566 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: publishFlushedSegment
   [junit4]   2> 94566 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: publish sets newSegment delGen=9 seg=_4(4.10):C10
   [junit4]   2> 94566 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: now checkpoint "_0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10" [5 segments ; isCommit = false]
   [junit4]   2> 94566 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: 0 msec to checkpoint
   [junit4]   2> 94567 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: apply all deletes during flush
   [junit4]   2> 94567 T152 C17 oasu.LoggingInfoStream.message [BD][DocThread-1]: applyDeletes: infos=[_0(4.10):C11, _2(4.10):C1, _1(4.10):C1, _3(4.10):C100, _4(4.10):C10] packetCount=1
   [junit4]   2> 94567 T152 C17 oasu.LoggingInfoStream.message [BD][DocThread-1]: applyDeletes took 0 msec
   [junit4]   2> 94567 T152 C17 oasu.LoggingInfoStream.message [BD][DocThread-1]: prune sis=segments_1: _0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10 minGen=10 packetCount=1
   [junit4]   2> 94567 T152 C17 oasu.LoggingInfoStream.message [BD][DocThread-1]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 94567 T152 C17 oasu.LoggingInfoStream.message [DW][DocThread-1]: DocThread-1 finishFullFlush success=true
   [junit4]   2> 94567 T152 C17 oasu.LoggingInfoStream.message [TMP][DocThread-1]: findMerges: 5 segments
   [junit4]   2> 94567 T152 C17 oasu.LoggingInfoStream.message [TMP][DocThread-1]:   seg=_3(4.10):C100 size=0.003 MB [floored]
   [junit4]   2> 94568 T152 C17 oasu.LoggingInfoStream.message [TMP][DocThread-1]:   seg=_0(4.10):C11 size=0.001 MB [floored]
   [junit4]   2> 94568 T152 C17 oasu.LoggingInfoStream.message [TMP][DocThread-1]:   seg=_4(4.10):C10 size=0.001 MB [floored]
   [junit4]   2> 94568 T152 C17 oasu.LoggingInfoStream.message [TMP][DocThread-1]:   seg=_1(4.10):C1 size=0.001 MB [floored]
   [junit4]   2> 94568 T152 C17 oasu.LoggingInfoStream.message [TMP][DocThread-1]:   seg=_2(4.10):C1 size=0.001 MB [floored]
   [junit4]   2> 94568 T152 C17 oasu.LoggingInfoStream.message [TMP][DocThread-1]:   allowedSegmentCount=1 vs count=5 (eligible count=5) tooBigCount=0
   [junit4]   2> 94569 T152 C17 oasu.LoggingInfoStream.message [CMS][DocThread-1]: now merge
   [junit4]   2> 94569 T152 C17 oasu.LoggingInfoStream.message [CMS][DocThread-1]:   index: _0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10
   [junit4]   2> 94569 T152 C17 oasu.LoggingInfoStream.message [CMS][DocThread-1]:   no more merges pending; now return
   [junit4]   2> 94569 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: startCommit(): start
   [junit4]   2> 94569 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: startCommit index=_0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10 changeCount=14
   [junit4]   2> 94569 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: done all syncs: [_0_Lucene41_0.tip, _3.si, _0_Lucene41_0.tim, _1.nvd, _3_Lucene41_0.doc, _0.nvd, _1.nvm, _1.fnm, _2.nvd, _4_Lucene41_0.pos, _2.nvm, _2.fnm, _1_Lucene41_0.doc, _2.si, _3_Lucene41_0.tim, _2_Lucene41_0.tip, _2_Lucene41_0.tim, _3_Lucene41_0.tip, _4.fdt, _1_Lucene41_0.tip, _4_Lucene41_0.doc, _1_Lucene41_0.tim, _3.fdt, _0.nvm, _0.fnm, _3.fdx, _1.si, _2.fdt, _2_Lucene41_0.doc, _2.fdx, _0_Lucene41_0.pos, _4.fdx, _4_Lucene41_0.tip, _4_Lucene41_0.tim, _1.fdx, _1.fdt, _3_Lucene41_0.pos, _0_Lucene41_0.doc, _0.si, _3.nvd, _4.nvm, _4.fnm, _0.fdx, _3.nvm, _3.fnm, _2_Lucene41_0.pos, _4.nvd, _0.fdt, _4.si, _1_Lucene41_0.pos]
   [junit4]   2> 94569 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: commit: pendingCommit != null
   [junit4]   2> 94572 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: commit: wrote segments file "segments_2"
   [junit4]   2> 94573 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: now checkpoint "_0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10" [5 segments ; isCommit = true]
   [junit4]   2> 94573 T152 C17 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@3c963ec lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\index),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@3c963ec lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\index),segFN=segments_2,generation=2}
   [junit4]   2> 94573 T152 C17 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 94574 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: deleteCommits: now decRef commit "segments_1"
   [junit4]   2> 94574 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: delete "segments_1"
   [junit4]   2> 94574 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: 1 msec to checkpoint
   [junit4]   2> 94574 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: commit: took 71.0 msec
   [junit4]   2> 94574 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: commit: done
   [junit4]   2> 94577 T152 C17 oasu.LoggingInfoStream.message [DW][DocThread-1]: anyChanges? numDocsInRam=348 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 94577 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: nrtIsCurrent: infoVersion matches: false; DW changes: true; BD changes: false
   [junit4]   2> 94577 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: flush at getReader
   [junit4]   2> 94577 T152 C17 oasu.LoggingInfoStream.message [DW][DocThread-1]: startFullFlush
   [junit4]   2> 94577 T152 C17 oasu.LoggingInfoStream.message [DW][DocThread-1]: anyChanges? numDocsInRam=348 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 94577 T152 C17 oasu.LoggingInfoStream.message [DWFC][DocThread-1]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 204 deleted terms (unique count=204) bytesUsed=47524, segment=_6, aborting=false, numDocsInRAM=164, deleteQueue=DWDQ: [ generation: 3 ]]
   [junit4]   2> 94577 T152 C17 oasu.LoggingInfoStream.message [DWFC][DocThread-1]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 255 deleted terms (unique count=255) bytesUsed=59398, segment=_5, aborting=false, numDocsInRAM=129, deleteQueue=DWDQ: [ generation: 3 ]]
   [junit4]   2> 94577 T152 C17 oasu.LoggingInfoStream.message [DWFC][DocThread-1]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 54 deleted terms (unique count=54) bytesUsed=12582, segment=_7, aborting=false, numDocsInRAM=55, deleteQueue=DWDQ: [ generation: 3 ]]
   [junit4]   2> 94578 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flush postings as segment _6 numDocs=164
   [junit4]   2> 94582 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: new segment has 0 deleted docs
   [junit4]   2> 94582 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 94582 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushedFiles=[_6_Lucene41_0.tip, _6.fdt, _6_Lucene41_0.doc, _6_Lucene41_0.tim, _6.nvm, _6.fnm, _6.fdx, _6_Lucene41_0.pos, _6.nvd]
   [junit4]   2> 94583 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushed codec=Lucene49
   [junit4]   2> 94583 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushed: segment=_6 ramUsed=0.127 MB newFlushedSize(includes docstores)=0.005 MB docs/MB=32,937.457
   [junit4]   2> 94583 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flush postings as segment _5 numDocs=129
   [junit4]   2> 94586 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: new segment has 0 deleted docs
   [junit4]   2> 94586 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 94586 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushedFiles=[_5.nvm, _5.fnm, _5_Lucene41_0.tip, _5.fdt, _5_Lucene41_0.doc, _5_Lucene41_0.tim, _5.nvd, _5_Lucene41_0.pos, _5.fdx]
   [junit4]   2> 94586 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushed codec=Lucene49
   [junit4]   2> 94586 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushed: segment=_5 ramUsed=0.145 MB newFlushedSize(includes docstores)=0.004 MB docs/MB=31,260.99
   [junit4]   2> 94586 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flush postings as segment _7 numDocs=55
   [junit4]   2> 94590 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: new segment has 0 deleted docs
   [junit4]   2> 94590 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 94590 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushedFiles=[_7.nvm, _7_Lucene41_0.pos, _7_Lucene41_0.doc, _7.fnm, _7.fdt, _7_Lucene41_0.tim, _7.nvd, _7_Lucene41_0.tip, _7.fdx]
   [junit4]   2> 94592 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushed codec=Lucene49
   [junit4]   2> 94592 T152 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-1]: flushed: segment=_7 ramUsed=0.151 MB newFlushedSize(includes docstores)=0.002 MB docs/MB=22,267.058
   [junit4]   2> 94592 T152 C17 oasu.LoggingInfoStream.message [DW][DocThread-1]: publishFlushedSegment seg-private updates=null
   [junit4]   2> 94592 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: publishFlushedSegment
   [junit4]   2> 94592 T152 C17 oasu.LoggingInfoStream.message [BD][DocThread-1]: push deletes  348 deleted terms (unique count=348) bytesUsed=2096 delGen=11 packetCount=1 totBytesUsed=2096
   [junit4]   2> 94594 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: publish sets newSegment delGen=12 seg=_6(4.10):C164
   [junit4]   2> 94595 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: now checkpoint "_0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10 _6(4.10):C164" [6 segments ; isCommit = false]
   [junit4]   2> 94595 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: 0 msec to checkpoint
   [junit4]   2> 94595 T152 C17 oasu.LoggingInfoStream.message [DW][DocThread-1]: publishFlushedSegment seg-private updates=null
   [junit4]   2> 94595 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: publishFlushedSegment
   [junit4]   2> 94595 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: publish sets newSegment delGen=13 seg=_5(4.10):C129
   [junit4]   2> 94596 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: now checkpoint "_0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10 _6(4.10):C164 _5(4.10):C129" [7 segments ; isCommit = false]
   [junit4]   2> 94596 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: 0 msec to checkpoint
   [junit4]   2> 94596 T152 C17 oasu.LoggingInfoStream.message [DW][DocThread-1]: publishFlushedSegment seg-private updates=null
   [junit4]   2> 94596 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: publishFlushedSegment
   [junit4]   2> 94596 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: publish sets newSegment delGen=14 seg=_7(4.10):C55
   [junit4]   2> 94598 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: now checkpoint "_0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10 _6(4.10):C164 _5(4.10):C129 _7(4.10):C55" [8 segments ; isCommit = false]
   [junit4]   2> 94598 T152 C17 oasu.LoggingInfoStream.message [IFD][DocThread-1]: 0 msec to checkpoint
   [junit4]   2> 94599 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: apply all deletes during flush
   [junit4]   2> 94599 T152 C17 oasu.LoggingInfoStream.message [BD][DocThread-1]: applyDeletes: infos=[_0(4.10):C11, _2(4.10):C1, _1(4.10):C1, _3(4.10):C100, _4(4.10):C10, _6(4.10):C164, _5(4.10):C129, _7(4.10):C55] packetCount=1
   [junit4]   2> 94611 T152 C17 oasu.LoggingInfoStream.message [BD][DocThread-1]: seg=_4(4.10):C10 segGen=10 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericDVUpdates=0,binaryDVUpdates=0)] newDelCount=0
   [junit4]   2> 94612 T152 C17 oasu.LoggingInfoStream.message [BD][DocThread-1]: seg=_3(4.10):C100 segGen=10 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericDVUpdates=0,binaryDVUpdates=0)] newDelCount=0
   [junit4]   2> 94616 T152 C17 oasu.LoggingInfoStream.message [BD][DocThread-1]: seg=_1(4.10):C1 segGen=10 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericDVUpdates=0,binaryDVUpdates=0)] newDelCount=0
   [junit4]   2> 94617 T152 C17 oasu.LoggingInfoStream.message [BD][DocThread-1]: seg=_2(4.10):C1 segGen=10 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericDVUpdates=0,binaryDVUpdates=0)] newDelCount=0
   [junit4]   2> 94617 T152 C17 oasu.LoggingInfoStream.message [BD][DocThread-1]: seg=_0(4.10):C11 segGen=10 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericDVUpdates=0,binaryDVUpdates=0)] newDelCount=0
   [junit4]   2> 94617 T152 C17 oasu.LoggingInfoStream.message [BD][DocThread-1]: applyDeletes took 18 msec
   [junit4]   2> 94617 T152 C17 oasu.LoggingInfoStream.message [BD][DocThread-1]: prune sis=segments_2: _0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10 _6(4.10):C164 _5(4.10):C129 _7(4.10):C55 minGen=15 packetCount=1
   [junit4]   2> 94618 T152 C17 oasu.LoggingInfoStream.message [BD][DocThread-1]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 94620 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: return reader version=17 reader=StandardDirectoryReader(segments_2:17:nrt _0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10 _6(4.10):C164 _5(4.10):C129 _7(4.10):C55)
   [junit4]   2> 94620 T152 C17 oasu.LoggingInfoStream.message [DW][DocThread-1]: DocThread-1 finishFullFlush success=true
   [junit4]   2> 94620 T152 C17 oasu.LoggingInfoStream.message [TMP][DocThread-1]: findMerges: 8 segments
   [junit4]   2> 94620 T152 C17 oasu.LoggingInfoStream.message [TMP][DocThread-1]:   seg=_6(4.10):C164 size=0.005 MB [floored]
   [junit4]   2> 94620 T152 C17 oasu.LoggingInfoStream.message [TMP][DocThread-1]:   seg=_5(4.10):C129 size=0.004 MB [floored]
   [junit4]   2> 94620 T152 C17 oasu.LoggingInfoStream.message [TMP][DocThread-1]:   seg=_3(4.10):C100 size=0.003 MB [floored]
   [junit4]   2> 94620 T152 C17 oasu.LoggingInfoStream.message [TMP][DocThread-1]:   seg=_7(4.10):C55 size=0.002 MB [floored]
   [junit4]   2> 94620 T152 C17 oasu.LoggingInfoStream.message [TMP][DocThread-1]:   seg=_0(4.10):C11 size=0.001 MB [floored]
   [junit4]   2> 94620 T152 C17 oasu.LoggingInfoStream.message [TMP][DocThread-1]:   seg=_4(4.10):C10 size=0.001 MB [floored]
   [junit4]   2> 94621 T152 C17 oasu.LoggingInfoStream.message [TMP][DocThread-1]:   seg=_1(4.10):C1 size=0.001 MB [floored]
   [junit4]   2> 94625 T152 C17 oasu.LoggingInfoStream.message [TMP][DocThread-1]:   seg=_2(4.10):C1 size=0.001 MB [floored]
   [junit4]   2> 94625 T152 C17 oasu.LoggingInfoStream.message [TMP][DocThread-1]:   allowedSegmentCount=1 vs count=8 (eligible count=8) tooBigCount=0
   [junit4]   2> 94625 T152 C17 oasu.LoggingInfoStream.message [CMS][DocThread-1]: now merge
   [junit4]   2> 94625 T152 C17 oasu.LoggingInfoStream.message [CMS][DocThread-1]:   index: _0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10 _6(4.10):C164 _5(4.10):C129 _7(4.10):C55
   [junit4]   2> 94625 T152 C17 oasu.LoggingInfoStream.message [CMS][DocThread-1]:   no more merges pending; now return
   [junit4]   2> 94625 T152 C17 oasu.LoggingInfoStream.message [IW][DocThread-1]: getReader took 48 msec
   [junit4]   2> 94625 T152 C17 oass.SolrIndexSearcher.<init> Opening Searcher@3bc181b1[collection1] main
   [junit4]   2> 94625 T152 C17 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 94626 T155 C17 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 94627 T155 C17 oasu.LoggingInfoStream.message [IW][DocThread-4]: commit: start
   [junit4]   2> 94627 T155 C17 oasu.LoggingInfoStream.message [IW][DocThread-4]: commit: enter lock
   [junit4]   2> 94627 T155 C17 oasu.LoggingInfoStream.message [IW][DocThread-4]: commit: now prepare
   [junit4]   2> 94627 T155 C17 oasu.LoggingInfoStream.message [IW][DocThread-4]: prepareCommit: flush
   [junit4]   2> 94628 T155 C17 oasu.LoggingInfoStream.message [IW][DocThread-4]:   index before flush _0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10 _6(4.10):C164 _5(4.10):C129 _7(4.10):C55
   [junit4]   2> 94628 T155 C17 oasu.LoggingInfoStream.message [DW][DocThread-4]: startFullFlush
   [junit4]   2> 94628 T155 C17 oasu.LoggingInfoStream.message [DW][DocThread-4]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 94628 T155 C17 oasu.LoggingInfoStream.message [IW][DocThread-4]: apply all deletes during flush
   [junit4]   2> 94628 T155 C17 oasu.LoggingInfoStream.message [BD][DocThread-4]: applyDeletes: no deletes; skipping
   [junit4]   2> 94628 T155 C17 oasu.LoggingInfoStream.message [BD][DocThread-4]: prune sis=segments_2: _0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10 _6(4.10):C164 _5(4.10):C129 _7(4.10):C55 minGen=15 packetCount=0
   [junit4]   2> 94628 T155 C17 oasu.LoggingInfoStream.message [DW][DocThread-4]: DocThread-4 finishFullFlush success=true
   [junit4]   2> 94628 T155 C17 oasu.LoggingInfoStream.message [IW][DocThread-4]: startCommit(): start
   [junit4]   2> 94628 T155 C17 oasu.LoggingInfoStream.message [IW][DocThread-4]: startCommit index=_0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10 _6(4.10):C164 _5(4.10):C129 _7(4.10):C55 changeCount=18
   [junit4]   2> 94632 T155 C17 oasu.LoggingInfoStream.message [IW][DocThread-4]: done all syncs: [_0_Lucene41_0.tip, _3.si, _5_Lucene41_0.tip, _0_Lucene41_0.tim, _1.nvd, _3_Lucene41_0.doc, _5_Lucene41_0.tim, _0.nvd, _6_Lucene41_0.pos, _1.nvm, _1.fnm, _2.nvd, _4_Lucene41_0.pos, _6.fdt, _6_Lucene41_0.doc, _7.si, _2.nvm, _2.fnm, _1_Lucene41_0.doc, _2.si, _5.fdt, _3_Lucene41_0.tim, _2_Lucene41_0.tip, _5_Lucene41_0.doc, _2_Lucene41_0.tim, _3_Lucene41_0.tip, _4.fdt, _1_Lucene41_0.tip, _4_Lucene41_0.doc, _1_Lucene41_0.tim, _5_Lucene41_0.pos, _3.fdt, _6.si, _0.nvm, _0.fnm, _3.fdx, _1.si, _6.nvm, _6.fnm, _7_Lucene41_0.doc, _2.fdt, _2_Lucene41_0.doc, _2.fdx, _0_Lucene41_0.pos, _4.fdx, _6.nvd, _4_Lucene41_0.tip, _7.nvm, _7_Lucene41_0.pos, _4_Lucene41_0.tim, _7.fnm, _1.fdx, _7.nvd, _5.si, _1.fdt, _5.fdx, _3_Lucene41_0.pos, _0_Lucene41_0.doc, _0.si, _3.nvd, _4.nvm, _4.fnm, _6.fdx, _7_Lucene41_0.tim, _0.fdx, _3.nvm, _3.fnm, _2_Lucene41_0.pos, _4.nvd, _7_Lucene41_0.tip, _0.fdt, _5.nvm, _5.fnm, _6_Lucene41_0.tip, _6_Lucene41_0.tim, _5.nvd, _7.fdt, _4.si, _7.fdx, _1_Lucene41_0.pos]
   [junit4]   2> 94632 T155 C17 oasu.LoggingInfoStream.message [IW][DocThread-4]: commit: pendingCommit != null
   [junit4]   2> 94632 T155 C17 oasu.LoggingInfoStream.message [IW][DocThread-4]: commit: wrote segments file "segments_3"
   [junit4]   2> 94633 T155 C17 oasu.LoggingInfoStream.message [IFD][DocThread-4]: now checkpoint "_0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10 _6(4.10):C164 _5(4.10):C129 _7(4.10):C55" [8 segments ; isCommit = true]
   [junit4]   2> 94633 T155 C17 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@3c963ec lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\index),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@3c963ec lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\index),segFN=segments_3,generation=3}
   [junit4]   2> 94633 T155 C17 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
   [junit4]   2> 94633 T155 C17 oasu.LoggingInfoStream.message [IFD][DocThread-4]: deleteCommits: now decRef commit "segments_2"
   [junit4]   2> 94633 T155 C17 oasu.LoggingInfoStream.message [IFD][DocThread-4]: delete "segments_2"
   [junit4]   2> 94633 T155 C17 oasu.LoggingInfoStream.message [IFD][DocThread-4]: 0 msec to checkpoint
   [junit4]   2> 94634 T155 C17 oasu.LoggingInfoStream.message [IW][DocThread-4]: commit: took 5.1 msec
   [junit4]   2> 94634 T155 C17 oasu.LoggingInfoStream.message [IW][DocThread-4]: commit: done
   [junit4]   2> 94634 T155 C17 oasc.SolrCore.getSearcher WARN [collection1] PERFORMANCE WARNING: Overlapping onDeckSearchers=2
   [junit4]   2> 94635 T155 C17 oasu.LoggingInfoStream.message [DW][DocThread-4]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 94635 T155 C17 oasu.LoggingInfoStream.message [IW][DocThread-4]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
   [junit4]   2> 94635 T155 C17 oasu.LoggingInfoStream.message [DW][DocThread-4]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 94635 T155 C17 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 94635 T155 C17 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 94636 T151 C17 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 94636 T151 C17 oasu.LoggingInfoStream.message [DW][DocThread-0]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 94636 T151 C17 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 94636 T151 C17 oasc.SolrCore.getSearcher WARN [collection1] Error opening new searcher. exceeded limit of maxWarmingSearchers=2, try again later.
   [junit4]   2> 94636 T151 C17 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=false&waitSearcher=true} {} 0 94
   [junit4]   2> 94636 T151 C17 oasc.SolrException.log ERROR org.apache.solr.common.SolrException: Error opening new searcher. exceeded limit of maxWarmingSearchers=2, try again later.
   [junit4]   2> 		at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1662)
   [junit4]   2> 		at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1420)
   [junit4]   2> 		at org.apache.solr.update.DirectUpdateHandler2.commit(DirectUpdateHandler2.java:615)
   [junit4]   2> 		at org.apache.solr.update.processor.RunUpdateProcessor.processCommit(RunUpdateProcessorFactory.java:95)
   [junit4]   2> 		at org.apache.solr.update.processor.UpdateRequestProcessor.processCommit(UpdateRequestProcessor.java:64)
   [junit4]   2> 		at org.apache.solr.update.processor.DistributedUpdateProcessor.doLocalCommit(DistributedUpdateProcessor.java:1648)
   [junit4]   2> 		at org.apache.solr.update.processor.DistributedUpdateProcessor.processCommit(DistributedUpdateProcessor.java:1625)
   [junit4]   2> 		at org.apache.solr.update.processor.LogUpdateProcessor.processCommit(LogUpdateProcessorFactory.java:157)
   [junit4]   2> 		at org.apache.solr.handler.RequestHandlerUtils.handleCommit(RequestHandlerUtils.java:69)
   [junit4]   2> 		at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:68)
   [junit4]   2> 		at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:135)
   [junit4]   2> 		at org.apache.solr.core.SolrCore.execute(SolrCore.java:1966)
   [junit4]   2> 		at org.apache.solr.client.solrj.embedded.EmbeddedSolrServer.request(EmbeddedSolrServer.java:150)
   [junit4]   2> 		at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:124)
   [junit4]   2> 		at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:168)
   [junit4]   2> 		at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:146)
   [junit4]   2> 		at org.apache.solr.client.solrj.LargeVolumeTestBase$DocThread.run(LargeVolumeTestBase.java:112)
   [junit4]   2> 	
   [junit4]   2> 94638 T151 oascs.LargeVolumeTestBase$DocThread.run Caught benign exception during commit: Error opening new searcher. exceeded limit of maxWarmingSearchers=2, try again later.
   [junit4]   2> 94640 T153 C17 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 94640 T153 C17 oasu.LoggingInfoStream.message [DW][DocThread-2]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 94640 T153 C17 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 94640 T153 C17 oasc.SolrCore.getSearcher WARN [collection1] Error opening new searcher. exceeded limit of maxWarmingSearchers=2, try again later.
   [junit4]   2> 94640 T153 C17 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=false&waitSearcher=true} {} 0 95
   [junit4]   2> 94640 T153 C17 oasc.SolrException.log ERROR org.apache.solr.common.SolrException: Error opening new searcher. exceeded limit of maxWarmingSearchers=2, try again later.
   [junit4]   2> 		at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1662)
   [junit4]   2> 		at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1420)
   [junit4]   2> 		at org.apache.solr.update.DirectUpdateHandler2.commit(DirectUpdateHandler2.java:615)
   [junit4]   2> 		at org.apache.solr.update.processor.RunUpdateProcessor.processCommit(RunUpdateProcessorFactory.java:95)
   [junit4]   2> 		at org.apache.solr.update.processor.UpdateRequestProcessor.processCommit(UpdateRequestProcessor.java:64)
   [junit4]   2> 		at org.apache.solr.update.processor.DistributedUpdateProcessor.doLocalCommit(DistributedUpdateProcessor.java:1648)
   [junit4]   2> 		at org.apache.solr.update.processor.DistributedUpdateProcessor.processCommit(DistributedUpdateProcessor.java:1625)
   [junit4]   2> 		at org.apache.solr.update.processor.LogUpdateProcessor.processCommit(LogUpdateProcessorFactory.java:157)
   [junit4]   2> 		at org.apache.solr.handler.RequestHandlerUtils.handleCommit(RequestHandlerUtils.java:69)
   [junit4]   2> 		at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:68)
   [junit4]   2> 		at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:135)
   [junit4]   2> 		at org.apache.solr.core.SolrCore.execute(SolrCore.java:1966)
   [junit4]   2> 		at org.apache.solr.client.solrj.embedded.EmbeddedSolrServer.request(EmbeddedSolrServer.java:150)
   [junit4]   2> 		at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:124)
   [junit4]   2> 		at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:168)
   [junit4]   2> 		at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:146)
   [junit4]   2> 		at org.apache.solr.client.solrj.LargeVolumeTestBase$DocThread.run(LargeVolumeTestBase.java:112)
   [junit4]   2> 	
   [junit4]   2> 94641 T153 oascs.LargeVolumeTestBase$DocThread.run Caught benign exception during commit: Error opening new searcher. exceeded limit of maxWarmingSearchers=2, try again later.
   [junit4]   2> 94646 T154 C17 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[T3:0 (1476091712071794688), T3:1 (1476091712077037571), T3:2 (1476091712077037572), T3:3 (1476091712077037573), T3:4 (1476091712077037574), T3:5 (1476091712078086144), T3:6 (1476091712078086145), T3:7 (1476091712078086146), T3:8 (1476091712078086147), T3:9 (1476091712078086148), ... (100 adds)]} 0 171
   [junit4]   2> 94648 T154 C17 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 94648 T154 C17 oasu.LoggingInfoStream.message [IW][DocThread-3]: commit: start
   [junit4]   2> 94648 T154 C17 oasu.LoggingInfoStream.message [IW][DocThread-3]: commit: enter lock
   [junit4]   2> 94648 T154 C17 oasu.LoggingInfoStream.message [IW][DocThread-3]: commit: now prepare
   [junit4]   2> 94648 T154 C17 oasu.LoggingInfoStream.message [IW][DocThread-3]: prepareCommit: flush
   [junit4]   2> 94648 T154 C17 oasu.LoggingInfoStream.message [IW][DocThread-3]:   index before flush _0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10 _6(4.10):C164 _5(4.10):C129 _7(4.10):C55
   [junit4]   2> 94648 T154 C17 oasu.LoggingInfoStream.message [DW][DocThread-3]: startFullFlush
   [junit4]   2> 94648 T154 C17 oasu.LoggingInfoStream.message [DW][DocThread-3]: anyChanges? numDocsInRam=29 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 94648 T154 C17 oasu.LoggingInfoStream.message [DWFC][DocThread-3]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 28 deleted terms (unique count=28) bytesUsed=6524, segment=_8, aborting=false, numDocsInRAM=29, deleteQueue=DWDQ: [ generation: 5 ]]
   [junit4]   2> 94648 T154 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-3]: flush postings as segment _8 numDocs=29
   [junit4]   2> 94650 T154 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-3]: new segment has 0 deleted docs
   [junit4]   2> 94650 T154 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-3]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 94650 T154 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-3]: flushedFiles=[_8.fdx, _8_Lucene41_0.pos, _8.fdt, _8.fnm, _8.nvm, _8_Lucene41_0.doc, _8_Lucene41_0.tim, _8_Lucene41_0.tip, _8.nvd]
   [junit4]   2> 94650 T154 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-3]: flushed codec=Lucene49
   [junit4]   2> 94650 T154 C17 oasu.LoggingInfoStream.message [DWPT][DocThread-3]: flushed: segment=_8 ramUsed=0.079 MB newFlushedSize(includes docstores)=0.002 MB docs/MB=15,546.372
   [junit4]   2> 94650 T154 C17 oasu.LoggingInfoStream.message [DW][DocThread-3]: publishFlushedSegment seg-private updates=null
   [junit4]   2> 94653 T154 C17 oasu.LoggingInfoStream.message [IW][DocThread-3]: publishFlushedSegment
   [junit4]   2> 94653 T154 C17 oasu.LoggingInfoStream.message [BD][DocThread-3]: push deletes  29 deleted terms (unique count=29) bytesUsed=1072 delGen=17 packetCount=1 totBytesUsed=1072
   [junit4]   2> 94653 T154 C17 oasu.LoggingInfoStream.message [IW][DocThread-3]: publish sets newSegment delGen=18 seg=_8(4.10):C29
   [junit4]   2> 94653 T154 C17 oasu.LoggingInfoStream.message [IFD][DocThread-3]: now checkpoint "_0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10 _6(4.10):C164 _5(4.10):C129 _7(4.10):C55 _8(4.10):C29" [9 segments ; isCommit = false]
   [junit4]   2> 94653 T154 C17 oasu.LoggingInfoStream.message [IFD][DocThread-3]: 0 msec to checkpoint
   [junit4]   2> 94653 T154 C17 oasu.LoggingInfoStream.message [IW][DocThread-3]: apply all deletes during flush
   [junit4]   2> 94653 T154 C17 oasu.LoggingInfoStream.message [BD][DocThread-3]: applyDeletes: infos=[_0(4.10):C11, _2(4.10):C1, _1(4.10):C1, _3(4.10):C100, _4(4.10):C10, _6(4.10):C164, _5(4.10):C129, _7(4.10):C55, _8(4.10):C29] packetCount=1
   [junit4]   2> 94653 T154 C17 oasu.LoggingInfoStream.message [BD][DocThread-3]: seg=_7(4.10):C55 segGen=15 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericDVUpdates=0,binaryDVUpdates=0)] newDelCount=0
   [junit4]   2> 94653 T154 C17 oasu.LoggingInfoStream.message [BD][DocThread-3]: seg=_5(4.10):C129 segGen=15 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericDVUpdates=0,binaryDVUpdates=0)] newDelCount=0
   [junit4]   2> 94653 T154 C17 oasu.LoggingInfoStream.message [BD][DocThread-3]: seg=_6(4.10):C164 segGen=15 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericDVUpdates=0,binaryDVUpdates=0)] newDelCount=0
   [junit4]   2> 94653 T154 C17 oasu.LoggingInfoStream.message [BD][DocThread-3]: seg=_4(4.10):C10 segGen=15 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericDVUpdates=0,binaryDVUpdates=0)] newDelCount=0
   [junit4]   2> 94657 T154 C17 oasu.LoggingInfoStream.message [BD][DocThread-3]: seg=_3(4.10):C100 segGen=15 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericDVUpdates=0,binaryDVUpdates=0)] newDelCount=0
   [junit4]   2> 94657 T154 C17 oasu.LoggingInfoStream.message [BD][DocThread-3]: seg=_1(4.10):C1 segGen=15 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericDVUpdates=0,binaryDVUpdates=0)] newDelCount=0
   [junit4]   2> 94657 T154 C17 oasu.LoggingInfoStream.message [BD][DocThread-3]: seg=_2(4.10):C1 segGen=15 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericDVUpdates=0,binaryDVUpdates=0)] newDelCount=0
   [junit4]   2> 94657 T154 C17 oasu.LoggingInfoStream.message [BD][DocThread-3]: seg=_0(4.10):C11 segGen=15 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericDVUpdates=0,binaryDVUpdates=0)] newDelCount=0
   [junit4]   2> 94657 T154 C17 oasu.LoggingInfoStream.message [BD][DocThread-3]: applyDeletes took 4 msec
   [junit4]   2> 94657 T154 C17 oasu.LoggingInfoStream.message [BD][DocThread-3]: prune sis=segments_3: _0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10 _6(4.10):C164 _5(4.10):C129 _7(4.10):C55 _8(4.10):C29 minGen=19 packetCount=1
   [junit4]   2> 94657 T154 C17 oasu.LoggingInfoStream.message [BD][DocThread-3]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 94657 T154 C17 oasu.LoggingInfoStream.message [DW][DocThread-3]: DocThread-3 finishFullFlush success=true
   [junit4]   2> 94657 T154 C17 oasu.LoggingInfoStream.message [TMP][DocThread-3]: findMerges: 9 segments
   [junit4]   2> 94657 T154 C17 oasu.LoggingInfoStream.message [TMP][DocThread-3]:   seg=_6(4.10):C164 size=0.005 MB [floored]
   [junit4]   2> 94657 T154 C17 oasu.LoggingInfoStream.message [TMP][DocThread-3]:   seg=_5(4.10):C129 size=0.004 MB [floored]
   [junit4]   2> 94657 T154 C17 oasu.LoggingInfoStream.message [TMP][DocThread-3]:   seg=_3(4.10):C100 size=0.003 MB [floored]
   [junit4]   2> 94657 T154 C17 oasu.LoggingInfoStream.message [TMP][DocThread-3]:   seg=_7(4.10):C55 size=0.002 MB [floored]
   [junit4]   2> 94657 T154 C17 oasu.LoggingInfoStream.message [TMP][DocThread-3]:   seg=_8(4.10):C29 size=0.002 MB [floored]
   [junit4]   2> 94657 T154 C17 oasu.LoggingInfoStream.message [TMP][DocThread-3]:   seg=_0(4.10):C11 size=0.001 MB [floored]
   [junit4]   2> 94659 T154 C17 oasu.LoggingInfoStream.message [TMP][DocThread-3]:   seg=_4(4.10):C10 size=0.001 MB [floored]
   [junit4]   2> 94661 T154 C17 oasu.LoggingInfoStream.message [TMP][DocThread-3]:   seg=_1(4.10):C1 size=0.001 MB [floored]
   [junit4]   2> 94661 T154 C17 oasu.LoggingInfoStream.message [TMP][DocThread-3]:   seg=_2(4.10):C1 size=0.001 MB [floored]
   [junit4]   2> 94661 T154 C17 oasu.LoggingInfoStream.message [TMP][DocThread-3]:   allowedSegmentCount=1 vs count=9 (eligible count=9) tooBigCount=0
   [junit4]   2> 94662 T154 C17 oasu.LoggingInfoStream.message [CMS][DocThread-3]: now merge
   [junit4]   2> 94662 T154 C17 oasu.LoggingInfoStream.message [CMS][DocThread-3]:   index: _0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10 _6(4.10):C164 _5(4.10):C129 _7(4.10):C55 _8(4.10):C29
   [junit4]   2> 94662 T154 C17 oasu.LoggingInfoStream.message [CMS][DocThread-3]:   no more merges pending; now return
   [junit4]   2> 94662 T154 C17 oasu.LoggingInfoStream.message [IW][DocThread-3]: startCommit(): start
   [junit4]   2> 94662 T154 C17 oasu.LoggingInfoStream.message [IW][DocThread-3]: startCommit index=_0(4.10):C11 _2(4.10):C1 _1(4.10):C1 _3(4.10):C100 _4(4.10):C10 _6(4.10):C164 _5(4.10):C129 _7(4.10):C55 _8(4.10):C29 changeCount=21
   [junit4]   2> 94662 T154 C17 oasu.LoggingInfoStream.message [IW][DocThread-3]: done all syncs: [_0_Lucene41_0.tip, _3.si, _5_Lucene41_0.tip, _8.fdx, _0_Lucene41_0.tim, _1.nvd, _3_Lucene41_0.doc, _8.fdt, _5_Lucene41_0.tim, _0.nvd, _6_Lucene41_0.pos, _1.nvm, _1.fnm, _2.nvd, _4_Lucene41_0.pos, _6.fdt, _6_Lucene41_0.doc, _7.si, _2.nvm, _2.fnm, _8_Lucene41_0.tim, _8_Lucene41_0.tip, _1_Lucene41_0.doc, _2.si, _5.fdt, _3_Lucene41_0.tim, _2_Lucene41_0.tip, _5_Lucene41_0.doc, _2_Lucene41_0.tim, _3_Lucene41_0.tip, _8.nvd, _4.fdt, _1_Lucene41_0.tip, _4_Lucene41_0.doc, _8.fnm, _8.nvm, _1_Lucene41_0.tim, _5_Lucene41_0.pos, _3.fdt, _6.si, _0.nvm, _0.fnm, _3.fdx, _1.si, _6.nvm, _6.fnm, _7_Lucene41_0.doc, _2.fdt, _2_Lucene41_0.doc, _2.fdx, _0_Lucene41_0.pos, _4.f

[...truncated too long message...]

2F9D6E994B6802]-worker]: SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker finishFullFlush success=true
   [junit4]   2> 94752 T146 C17 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: apply all deletes during flush
   [junit4]   2> 94752 T146 C17 oasu.LoggingInfoStream.message [BD][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: applyDeletes: no deletes; skipping
   [junit4]   2> 94752 T146 C17 oasu.LoggingInfoStream.message [BD][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: prune sis=segments_5: _9(4.10):C500 minGen=19 packetCount=0
   [junit4]   2> 94752 T146 C17 oasu.LoggingInfoStream.message [CMS][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: now merge
   [junit4]   2> 94752 T146 C17 oasu.LoggingInfoStream.message [CMS][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]:   index: _9(4.10):C500
   [junit4]   2> 94752 T146 C17 oasu.LoggingInfoStream.message [CMS][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]:   no more merges pending; now return
   [junit4]   2> 94752 T146 C17 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: waitForMerges
   [junit4]   2> 94752 T146 C17 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: waitForMerges done
   [junit4]   2> 94754 T146 C17 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: now call final commit()
   [junit4]   2> 94754 T146 C17 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: commit: start
   [junit4]   2> 94754 T146 C17 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: commit: enter lock
   [junit4]   2> 94754 T146 C17 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: commit: now prepare
   [junit4]   2> 94755 T146 C17 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: prepareCommit: flush
   [junit4]   2> 94755 T146 C17 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]:   index before flush _9(4.10):C500
   [junit4]   2> 94755 T146 C17 oasu.LoggingInfoStream.message [DW][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: startFullFlush
   [junit4]   2> 94755 T146 C17 oasu.LoggingInfoStream.message [DW][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 94755 T146 C17 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: apply all deletes during flush
   [junit4]   2> 94755 T146 C17 oasu.LoggingInfoStream.message [BD][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: applyDeletes: no deletes; skipping
   [junit4]   2> 94755 T146 C17 oasu.LoggingInfoStream.message [BD][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: prune sis=segments_5: _9(4.10):C500 minGen=19 packetCount=0
   [junit4]   2> 94755 T146 C17 oasu.LoggingInfoStream.message [DW][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker finishFullFlush success=true
   [junit4]   2> 94755 T146 C17 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: startCommit(): start
   [junit4]   2> 94755 T146 C17 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]:   skip startCommit(): no changes pending
   [junit4]   2> 94757 T146 C17 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: commit: pendingCommit == null; skip
   [junit4]   2> 94757 T146 C17 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: commit: done
   [junit4]   2> 94757 T146 C17 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeEmbeddedTest-seed#[1A2F9D6E994B6802]-worker]: at close: _9(4.10):C500
   [junit4]   2> 94762 T146 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 94762 T146 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 94762 T146 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\index;done=false>>]
   [junit4]   2> 94762 T146 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\index
   [junit4]   2> 94762 T146 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\;done=false>>]
   [junit4]   2> 94762 T146 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\
   [junit4]   2> 94765 T146 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 94765 T146 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=262031549
   [junit4]   2> NOTE: test params are: codec=FastCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST, chunkSize=448), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST, chunkSize=448)), sim=DefaultSimilarity, locale=es_DO, timezone=Asia/Sakhalin
   [junit4]   2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.8.0_11 (64-bit)/cpus=2,threads=1,free=121985024,total=204472320
   [junit4]   2> NOTE: All tests run in this JVM: [TestFastInputStream, QueryResponseTest, ContentStreamTest, AnlysisResponseBaseTest, TestDocumentObjectBinder, MergeIndexesEmbeddedTest, SolrExampleStreamingBinaryTest, JettyWebappTest, SolrExampleStreamingTest, TestSolrProperties, TestBatchUpdate, LargeVolumeEmbeddedTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=LargeVolumeEmbeddedTest -Dtests.seed=1A2F9D6E994B6802 -Dtests.slow=true -Dtests.locale=es_DO -Dtests.timezone=Asia/Sakhalin -Dtests.file.encoding=UTF-8
   [junit4] ERROR   0.00s | LargeVolumeEmbeddedTest (suite) <<<
   [junit4]    > Throwable #1: java.io.IOException: Could not remove the following files (in the order of attempts):
   [junit4]    >    C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\tlog\tlog.0000000000000000004
   [junit4]    >    C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001\tlog
   [junit4]    >    C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001\init-core-data-001
   [junit4]    >    C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeEmbeddedTest-1A2F9D6E994B6802-001
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([1A2F9D6E994B6802]:0)
   [junit4]    > 	at org.apache.lucene.util.TestUtil.rm(TestUtil.java:117)
   [junit4]    > 	at org.apache.lucene.util.LuceneTestCase$TemporaryFilesCleanupRule.afterAlways(LuceneTestCase.java:2675)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4] Completed in 1.95s, 1 test, 1 error <<< FAILURES!

[...truncated 126 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:474: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:454: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:202: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1308: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:923: There were test failures: 51 suites, 299 tests, 1 suite-level error

Total time: 150 minutes 18 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.8.0_11 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any