lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-4.x-Windows (64bit/jdk1.8.0_20-ea-b05) - Build # 3854 - Failure!
Date Tue, 08 Apr 2014 10:32:17 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/3854/
Java: 64bit/jdk1.8.0_20-ea-b05 -XX:-UseCompressedOops -XX:+UseG1GC

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

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.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\tlog\tlog.0000000000000000002    C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\tlog    C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001    C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-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.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\tlog\tlog.0000000000000000002
   C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\tlog
   C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001
   C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001

	at __randomizedtesting.SeedInfo.seed([EA97E28109CE696]:0)
	at org.apache.lucene.util.TestUtil.rm(TestUtil.java:118)
	at org.apache.lucene.util.LuceneTestCase$TemporaryFilesCleanupRule.afterAlways(LuceneTestCase.java:2387)
	at com.carrotsearch.randomizedtesting.rules.TestRuleAdapter$1.afterAlways(TestRuleAdapter.java:31)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:43)
	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:360)
	at java.lang.Thread.run(Thread.java:744)




Build Log:
[...truncated 12259 lines...]
   [junit4] Suite: org.apache.solr.client.solrj.embedded.LargeVolumeJettyTest
   [junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\init-core-data-001
   [junit4]   2> 202452 T606 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
   [junit4]   2> 202453 T606 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 202453 T606 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 202455 T606 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 202460 T606 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:63313
   [junit4]   2> 202460 T606 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 202460 T606 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 202460 T606 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr
   [junit4]   2> 202460 T606 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\'
   [junit4]   2> 202494 T606 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\solr.xml
   [junit4]   2> 202512 T606 oasc.CorePropertiesLocator.<init> Config-defined core root directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr
   [junit4]   2> 202512 T606 oasc.CoreContainer.<init> New CoreContainer 1632533280
   [junit4]   2> 202512 T606 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\]
   [junit4]   2> 202513 T606 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 202513 T606 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 202513 T606 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 202513 T606 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 202513 T606 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 202513 T606 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 202513 T606 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 202513 T606 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 202513 T606 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 202515 T606 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 202515 T606 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 202515 T606 oasc.CoreContainer.load Host Name: 
   [junit4]   2> 202518 T606 oasc.CorePropertiesLocator.discover Looking for core definitions underneath C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr
   [junit4]   2> 202550 T606 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\
   [junit4]   2> 202553 T606 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 202554 T616 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\'
   [junit4]   2> 202590 T616 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
   [junit4]   2> 202591 T616 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> 202592 T616 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> 202593 T616 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> 202593 T616 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> 202594 T616 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> 202594 T616 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> 202595 T616 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> 202595 T616 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> 202618 T616 oasu.SolrIndexConfig.<init> IndexWriter infoStream solr logging is enabled
   [junit4]   2> 202618 T616 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 202651 T616 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 202652 T616 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 202662 T616 oass.IndexSchema.readSchema [collection1] Schema name=example
   [junit4]   2> 202944 T616 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 202947 T616 oasr.RestManager$Registry.registerManagedResource Registered ManagedResource impl org.apache.solr.rest.schema.analysis.ManagedWordSetResource for path /schema/analysis/stopwords/english
   [junit4]   2> 202947 T616 oasr.RestManager$Registry.registerManagedResource Registered ManagedResource impl org.apache.solr.rest.schema.analysis.ManagedSynonymFilterFactory$SynonymManager for path /schema/analysis/synonyms/english
   [junit4]   2> 202960 T616 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 202965 T616 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 203002 T616 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> 203002 T616 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 203002 T616 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.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\
   [junit4]   2> 203002 T616 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2aea6882
   [junit4]   2> 203003 T616 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
   [junit4]   2> 203003 T616 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
   [junit4]   2> 203003 T616 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.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\
   [junit4]   2> 203003 T616 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.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\index/
   [junit4]   2> 203003 T616 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.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\index' doesn't exist. Creating new index...
   [junit4]   2> 203004 T616 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.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\index
   [junit4]   2> 203005 T616 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-339-thread-1]: init: current segments file is "null"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@5133d153
   [junit4]   2> 203007 T616 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-339-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 203007 T616 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-339-thread-1]: 0 msec to checkpoint
   [junit4]   2> 203007 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: init: create=true
   [junit4]   2> 203007 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: 
   [junit4]   2> 	dir=MockDirectoryWrapper(RAMDirectory@6f731e20 lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\index)
   [junit4]   2> 	index=
   [junit4]   2> 	version=4.8-SNAPSHOT
   [junit4]   2> 	matchVersion=LUCENE_48
   [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=Lucene46
   [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.ThreadAffinityDocumentsWriterThreadPool@2646574b
   [junit4]   2> 	readerPooling=false
   [junit4]   2> 	perThreadHardLimitMB=1945
   [junit4]   2> 	useCompoundFile=false
   [junit4]   2> 	checkIntegrityAtMerge=false
   [junit4]   2> 	
   [junit4]   2> 203007 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: now flush at close waitForMerges=true
   [junit4]   2> 203007 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]:   start flush: applyAllDeletes=true
   [junit4]   2> 203007 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]:   index before flush 
   [junit4]   2> 203007 T616 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-339-thread-1]: startFullFlush
   [junit4]   2> 203007 T616 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-339-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203007 T616 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-339-thread-1]: coreLoadExecutor-339-thread-1 finishFullFlush success=true
   [junit4]   2> 203007 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: apply all deletes during flush
   [junit4]   2> 203009 T616 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-339-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@4a69b53d minGen=9223372036854775807 packetCount=0
   [junit4]   2> 203009 T616 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-339-thread-1]: now merge
   [junit4]   2> 203009 T616 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-339-thread-1]:   index: 
   [junit4]   2> 203009 T616 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-339-thread-1]:   no more merges pending; now return
   [junit4]   2> 203010 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: waitForMerges
   [junit4]   2> 203010 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: waitForMerges done
   [junit4]   2> 203010 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: now call final commit()
   [junit4]   2> 203010 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: commit: start
   [junit4]   2> 203010 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: commit: enter lock
   [junit4]   2> 203010 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: commit: now prepare
   [junit4]   2> 203010 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: prepareCommit: flush
   [junit4]   2> 203010 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]:   index before flush 
   [junit4]   2> 203010 T616 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-339-thread-1]: startFullFlush
   [junit4]   2> 203010 T616 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-339-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203010 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: apply all deletes during flush
   [junit4]   2> 203012 T616 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-339-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@4a69b53d minGen=9223372036854775807 packetCount=0
   [junit4]   2> 203012 T616 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-339-thread-1]: coreLoadExecutor-339-thread-1 finishFullFlush success=true
   [junit4]   2> 203012 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: startCommit(): start
   [junit4]   2> 203012 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: startCommit index= changeCount=1
   [junit4]   2> 203013 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: done all syncs: []
   [junit4]   2> 203013 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: commit: pendingCommit != null
   [junit4]   2> 203013 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: commit: wrote segments file "segments_1"
   [junit4]   2> 203013 T616 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-339-thread-1]: now checkpoint "" [0 segments ; isCommit = true]
   [junit4]   2> 203013 T616 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@6f731e20 lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\index),segFN=segments_1,generation=1}
   [junit4]   2> 203013 T616 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 203015 T616 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-339-thread-1]: 0 msec to checkpoint
   [junit4]   2> 203015 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: commit: done
   [junit4]   2> 203015 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: at close: 
   [junit4]   2> 203016 T616 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
   [junit4]   2> 203016 T616 oasc.SolrCore.initWriters adding lazy queryResponseWriter: solr.VelocityResponseWriter
   [junit4]   2> 203017 T616 oasc.SolrCore.initWriters created velocity: solr.VelocityResponseWriter
   [junit4]   2> 203017 T616 oasc.SolrCore.initWriters created xslt: solr.XSLTResponseWriter
   [junit4]   2> 203017 T616 oasr.XSLTResponseWriter.init xsltCacheLifetimeSeconds=5
   [junit4]   2> 203020 T616 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 203020 T616 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
   [junit4]   2> 203022 T616 oasc.RequestHandlers.initHandlersFromConfig created /query: solr.SearchHandler
   [junit4]   2> 203023 T616 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 203023 T616 oasc.RequestHandlers.initHandlersFromConfig created /browse: solr.SearchHandler
   [junit4]   2> 203023 T616 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 203024 T616 oasc.RequestHandlers.initHandlersFromConfig created /update/json: solr.UpdateRequestHandler
   [junit4]   2> 203024 T616 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: solr.UpdateRequestHandler
   [junit4]   2> 203024 T616 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
   [junit4]   2> 203024 T616 oasc.RequestHandlers.initHandlersFromConfig created /update/extract: solr.extraction.ExtractingRequestHandler
   [junit4]   2> 203024 T616 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.FieldAnalysisRequestHandler
   [junit4]   2> 203024 T616 oasc.RequestHandlers.initHandlersFromConfig created /analysis/field: solr.FieldAnalysisRequestHandler
   [junit4]   2> 203024 T616 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
   [junit4]   2> 203025 T616 oasc.RequestHandlers.initHandlersFromConfig created /analysis/document: solr.DocumentAnalysisRequestHandler
   [junit4]   2> 203025 T616 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
   [junit4]   2> 203025 T616 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
   [junit4]   2> 203026 T616 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
   [junit4]   2> 203026 T616 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 203026 T616 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 203026 T616 oasc.RequestHandlers.initHandlersFromConfig created /spell: solr.SearchHandler
   [junit4]   2> 203026 T616 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 203026 T616 oasc.RequestHandlers.initHandlersFromConfig created /suggest: solr.SearchHandler
   [junit4]   2> 203026 T616 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 203027 T616 oasc.RequestHandlers.initHandlersFromConfig created /tvrh: solr.SearchHandler
   [junit4]   2> 203027 T616 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 203027 T616 oasc.RequestHandlers.initHandlersFromConfig created /terms: solr.SearchHandler
   [junit4]   2> 203027 T616 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 203027 T616 oasc.RequestHandlers.initHandlersFromConfig created /elevate: solr.SearchHandler
   [junit4]   2> 203037 T616 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 203039 T616 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 203041 T616 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 203044 T616 oasu.CommitTracker.<init> Hard AutoCommit: if uncommited for 15000ms; 
   [junit4]   2> 203044 T616 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 203045 T616 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-339-thread-1]: init: current segments file is "segments_1"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@5133d153
   [junit4]   2> 203045 T616 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-339-thread-1]: init: load commit "segments_1"
   [junit4]   2> 203045 T616 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@6f731e20 lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\index),segFN=segments_1,generation=1}
   [junit4]   2> 203045 T616 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 203046 T616 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-339-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 203047 T616 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-339-thread-1]: 1 msec to checkpoint
   [junit4]   2> 203048 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: init: create=false
   [junit4]   2> 203048 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: 
   [junit4]   2> 	dir=MockDirectoryWrapper(RAMDirectory@6f731e20 lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\index)
   [junit4]   2> 	index=
   [junit4]   2> 	version=4.8-SNAPSHOT
   [junit4]   2> 	matchVersion=LUCENE_48
   [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=Lucene46
   [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.ThreadAffinityDocumentsWriterThreadPool@1007aa4a
   [junit4]   2> 	readerPooling=false
   [junit4]   2> 	perThreadHardLimitMB=1945
   [junit4]   2> 	useCompoundFile=false
   [junit4]   2> 	checkIntegrityAtMerge=false
   [junit4]   2> 	
   [junit4]   2> 203048 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: flush at getReader
   [junit4]   2> 203048 T616 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-339-thread-1]: startFullFlush
   [junit4]   2> 203048 T616 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-339-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203048 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: apply all deletes during flush
   [junit4]   2> 203048 T616 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-339-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@7a79f279 minGen=9223372036854775807 packetCount=0
   [junit4]   2> 203048 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
   [junit4]   2> 203048 T616 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-339-thread-1]: coreLoadExecutor-339-thread-1 finishFullFlush success=true
   [junit4]   2> 203048 T616 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-339-thread-1]: getReader took 0 msec
   [junit4]   2> 203048 T616 oass.SolrIndexSearcher.<init> Opening Searcher@5157f347[collection1] main
   [junit4]   2> 203051 T616 oasr.ManagedResourceStorage$FileStorageIO.configure File-based storage initialized to use dir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\conf
   [junit4]   2> 203051 T616 oasr.RestManager.init Initializing RestManager with initArgs: {storageDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\conf\}
   [junit4]   2> 203051 T616 oasr.ManagedResourceStorage.load Reading _rest_managed.json using file:dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\conf
   [junit4]   2> 203052 T616 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
   [junit4]   2> 203052 T616 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 203052 T616 oasr.RestManager.init Initializing 2 registered ManagedResources
   [junit4]   2> 203052 T616 oasr.ManagedResourceStorage.load Reading _schema_analysis_stopwords_english.json using file:dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\conf
   [junit4]   2> 203052 T616 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _schema_analysis_stopwords_english.json using file:dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\conf
   [junit4]   2> 203052 T616 oasr.ManagedResource.reloadFromStorage Loaded initArgs {ignoreCase=true} for /schema/analysis/stopwords/english
   [junit4]   2> 203052 T616 oasrsa.ManagedWordSetResource.onManagedDataLoadedFromStorage Loaded 35 words for /schema/analysis/stopwords/english
   [junit4]   2> 203052 T616 oasr.ManagedResource.notifyObserversDuringInit Notified 1 observers of /schema/analysis/stopwords/english
   [junit4]   2> 203054 T616 oasr.ManagedResourceStorage.load Reading _schema_analysis_synonyms_english.json using file:dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\conf
   [junit4]   2> 203054 T616 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _schema_analysis_synonyms_english.json using file:dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\conf
   [junit4]   2> 203054 T616 oasr.ManagedResource.reloadFromStorage Loaded initArgs {ignoreCase=true,format=solr} for /schema/analysis/synonyms/english
   [junit4]   2> 203054 T616 oasrsa.ManagedSynonymFilterFactory$SynonymManager.onManagedDataLoadedFromStorage Loaded 3 synonym mappings for /schema/analysis/synonyms/english
   [junit4]   2> 203055 T616 oasr.ManagedResource.notifyObserversDuringInit Notified 1 observers of /schema/analysis/synonyms/english
   [junit4]   2> 203055 T616 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 203056 T616 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> 203056 T616 oashc.SpellCheckComponent.inform No queryConverter defined, using default converter
   [junit4]   2> 203056 T616 oashc.SuggestComponent.inform Initializing SuggestComponent
   [junit4]   2> 203056 T616 oasss.SolrSuggester.init init: {name=mySuggester,lookupImpl=FuzzyLookupFactory,dictionaryImpl=DocumentDictionaryFactory,field=cat,weightField=price,suggestAnalyzerFieldType=string}
   [junit4]   2> 203057 T616 oasss.SolrSuggester.init Dictionary loaded with params: {name=mySuggester,lookupImpl=FuzzyLookupFactory,dictionaryImpl=DocumentDictionaryFactory,field=cat,weightField=price,suggestAnalyzerFieldType=string}
   [junit4]   2> 203057 T616 oashc.QueryElevationComponent.inform Loading QueryElevation from: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\conf\elevate.xml
   [junit4]   2> 203105 T616 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 203108 T617 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@5157f347[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> ASYNC  NEW_CORE C100 name=collection1 org.apache.solr.core.SolrCore@1a56020
   [junit4]   2> 203110 T617 C100 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=2 
   [junit4]   2> 203110 T617 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 203110 T617 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
   [junit4]   2> 203110 T617 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
   [junit4]   2> 203110 T617 oashc.SuggestComponent$SuggesterListener.newSearcher Loading suggester index for: mySuggester
   [junit4]   2> 203110 T617 oasss.SolrSuggester.reload reload()
   [junit4]   2> 203110 T617 oasss.SolrSuggester.build build()
   [junit4]   2> 203117 T617 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5157f347[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 203118 T616 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 203119 T606 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0
   [junit4]   2> 203119 T606 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 203119 T606 oas.SolrJettyTestBase.createJetty Jetty Assigned Port#63313
   [junit4]   2> 203128 T606 oas.SolrTestCaseJ4.setUp ###Starting testMultiThreaded
   [junit4]   2> 203135 T611 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-611]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203135 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
   [junit4]   2> 203135 T611 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-611]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203135 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: flush at getReader
   [junit4]   2> 203135 T611 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-611]: startFullFlush
   [junit4]   2> 203135 T611 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-611]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203135 T611 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-611]: qtp1222893950-611: flush naked frozen global deletes
   [junit4]   2> 203139 T611 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-611]: push deletes  1 deleted queries bytesUsed=36 delGen=2 packetCount=1 totBytesUsed=36
   [junit4]   2> 203139 T611 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-611]: flush: push buffered updates:  1 deleted queries bytesUsed=36
   [junit4]   2> 203139 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: apply all deletes during flush
   [junit4]   2> 203139 T611 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-611]: prune sis=org.apache.lucene.index.SegmentInfos@7a79f279 minGen=9223372036854775807 packetCount=1
   [junit4]   2> 203139 T611 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-611]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 203139 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
   [junit4]   2> 203142 T611 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-611]: qtp1222893950-611 finishFullFlush success=true
   [junit4]   2> 203142 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: getReader took 7 msec
   [junit4]   2> 203144 T611 C100 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1464811478016065536)} 0 11
   [junit4]   2> 203147 T606 oascs.LargeVolumeTestBase.testMultiThreaded Started thread: 0
   [junit4]   2> 203148 T606 oascs.LargeVolumeTestBase.testMultiThreaded Started thread: 1
   [junit4]   2> 203150 T606 oascs.LargeVolumeTestBase.testMultiThreaded Started thread: 2
   [junit4]   2> 203151 T606 oascs.LargeVolumeTestBase.testMultiThreaded Started thread: 3
   [junit4]   2> 203156 T606 oascs.LargeVolumeTestBase.testMultiThreaded Started thread: 4
   [junit4]   2> 203188 T612 C100 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[T1:0 (1464811478054862848), T1:1 (1464811478059057152), T1:2 (1464811478059057153), T1:3 (1464811478059057154), T1:4 (1464811478061154304), T1:5 (1464811478061154305), T1:6 (1464811478061154306), T1:7 (1464811478061154307), T1:8 (1464811478061154308), T1:9 (1464811478061154309), ... (100 adds)]} 0 18
   [junit4]   2> 203209 T612 C100 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[T2:0 (1464811478077931520), T2:1 (1464811478077931521), T2:2 (1464811478077931522), T2:3 (1464811478077931523), T2:4 (1464811478077931524), T2:5 (1464811478078980096), T2:6 (1464811478078980097), T2:7 (1464811478078980098), T2:8 (1464811478078980099), T2:9 (1464811478080028672), ... (100 adds)]} 0 18
   [junit4]   2> 203213 T614 C100 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 203213 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: commit: start
   [junit4]   2> 203213 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: commit: enter lock
   [junit4]   2> 203213 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: commit: now prepare
   [junit4]   2> 203213 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: prepareCommit: flush
   [junit4]   2> 203213 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]:   index before flush 
   [junit4]   2> 203215 T614 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-614]: startFullFlush
   [junit4]   2> 203237 T614 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-614]: anyChanges? numDocsInRam=253 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203237 T614 C100 oasu.LoggingInfoStream.message [DWFC][qtp1222893950-614]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 252 deleted terms (unique count=252) bytesUsed=58686, segment=_0, aborting=false, numDocsInRAM=253, deleteQueue=DWDQ: [ generation: 2 ]]
   [junit4]   2> 203239 T614 C100 oasu.LoggingInfoStream.message [DWPT][qtp1222893950-614]: flush postings as segment _0 numDocs=253
   [junit4]   2> 203244 T614 C100 oasu.LoggingInfoStream.message [DWPT][qtp1222893950-614]: new segment has 0 deleted docs
   [junit4]   2> 203246 T614 C100 oasu.LoggingInfoStream.message [DWPT][qtp1222893950-614]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 203247 T614 C100 oasu.LoggingInfoStream.message [DWPT][qtp1222893950-614]: 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> 203247 T614 C100 oasu.LoggingInfoStream.message [DWPT][qtp1222893950-614]: flushed codec=Lucene46
   [junit4]   2> 203247 T614 C100 oasu.LoggingInfoStream.message [DWPT][qtp1222893950-614]: flushed: segment=_0 ramUsed=0.14 MB newFlushedSize(includes docstores)=0.008 MB docs/MB=32,930.701
   [junit4]   2> 203247 T614 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-614]: publishFlushedSegment seg-private updates=null
   [junit4]   2> 203253 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: publishFlushedSegment
   [junit4]   2> 203273 T614 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-614]: push deletes  253 deleted terms (unique count=253) bytesUsed=1024 delGen=4 packetCount=1 totBytesUsed=1024
   [junit4]   2> 203273 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: publish sets newSegment delGen=5 seg=_0(4.8):C253
   [junit4]   2> 203274 T614 C100 oasu.LoggingInfoStream.message [IFD][qtp1222893950-614]: now checkpoint "_0(4.8):C253" [1 segments ; isCommit = false]
   [junit4]   2> 203274 T614 C100 oasu.LoggingInfoStream.message [IFD][qtp1222893950-614]: 0 msec to checkpoint
   [junit4]   2> 203275 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: apply all deletes during flush
   [junit4]   2> 203275 T614 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-614]: applyDeletes: infos=[_0(4.8):C253] packetCount=1
   [junit4]   2> 203276 T614 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-614]: applyDeletes took 1 msec
   [junit4]   2> 203276 T614 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-614]: prune sis=org.apache.lucene.index.SegmentInfos@7a79f279 minGen=6 packetCount=1
   [junit4]   2> 203276 T614 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-614]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 203276 T614 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-614]: qtp1222893950-614 finishFullFlush success=true
   [junit4]   2> 203276 T614 C100 oasu.LoggingInfoStream.message [TMP][qtp1222893950-614]: findMerges: 1 segments
   [junit4]   2> 203290 T614 C100 oasu.LoggingInfoStream.message [TMP][qtp1222893950-614]:   seg=_0(4.8):C253 size=0.008 MB [floored]
   [junit4]   2> 203290 T614 C100 oasu.LoggingInfoStream.message [TMP][qtp1222893950-614]:   allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
   [junit4]   2> 203290 T614 C100 oasu.LoggingInfoStream.message [CMS][qtp1222893950-614]: now merge
   [junit4]   2> 203290 T614 C100 oasu.LoggingInfoStream.message [CMS][qtp1222893950-614]:   index: _0(4.8):C253
   [junit4]   2> 203290 T614 C100 oasu.LoggingInfoStream.message [CMS][qtp1222893950-614]:   no more merges pending; now return
   [junit4]   2> 203290 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: startCommit(): start
   [junit4]   2> 203290 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: startCommit index=_0(4.8):C253 changeCount=4
   [junit4]   2> 203294 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: done all syncs: [_0_Lucene41_0.tip, _0_Lucene41_0.doc, _0.si, _0_Lucene41_0.tim, _0.nvd, _0.fdx, _0.fdt, _0_Lucene41_0.pos, _0.nvm, _0.fnm]
   [junit4]   2> 203294 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: commit: pendingCommit != null
   [junit4]   2> 203294 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: commit: wrote segments file "segments_2"
   [junit4]   2> 203295 T614 C100 oasu.LoggingInfoStream.message [IFD][qtp1222893950-614]: now checkpoint "_0(4.8):C253" [1 segments ; isCommit = true]
   [junit4]   2> 203295 T614 C100 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@6f731e20 lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\index),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@6f731e20 lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\index),segFN=segments_2,generation=2}
   [junit4]   2> 203296 T614 C100 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 203296 T614 C100 oasu.LoggingInfoStream.message [IFD][qtp1222893950-614]: deleteCommits: now decRef commit "segments_1"
   [junit4]   2> 203296 T614 C100 oasu.LoggingInfoStream.message [IFD][qtp1222893950-614]: delete "segments_1"
   [junit4]   2> 203296 T614 C100 oasu.LoggingInfoStream.message [IFD][qtp1222893950-614]: 1 msec to checkpoint
   [junit4]   2> 203296 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: commit: done
   [junit4]   2> 203298 T614 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-614]: anyChanges? numDocsInRam=147 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203298 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: nrtIsCurrent: infoVersion matches: false; DW changes: true; BD changes: false
   [junit4]   2> 203298 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: flush at getReader
   [junit4]   2> 203298 T614 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-614]: startFullFlush
   [junit4]   2> 203298 T614 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-614]: anyChanges? numDocsInRam=147 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203298 T614 C100 oasu.LoggingInfoStream.message [DWFC][qtp1222893950-614]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 146 deleted terms (unique count=146) bytesUsed=34010, segment=_1, aborting=false, numDocsInRAM=147, deleteQueue=DWDQ: [ generation: 3 ]]
   [junit4]   2> 203298 T614 C100 oasu.LoggingInfoStream.message [DWPT][qtp1222893950-614]: flush postings as segment _1 numDocs=147
   [junit4]   2> 203303 T614 C100 oasu.LoggingInfoStream.message [DWPT][qtp1222893950-614]: new segment has 0 deleted docs
   [junit4]   2> 203303 T614 C100 oasu.LoggingInfoStream.message [DWPT][qtp1222893950-614]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 203303 T614 C100 oasu.LoggingInfoStream.message [DWPT][qtp1222893950-614]: 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> 203303 T614 C100 oasu.LoggingInfoStream.message [DWPT][qtp1222893950-614]: flushed codec=Lucene46
   [junit4]   2> 203304 T614 C100 oasu.LoggingInfoStream.message [DWPT][qtp1222893950-614]: flushed: segment=_1 ramUsed=0.113 MB newFlushedSize(includes docstores)=0.005 MB docs/MB=31,586.203
   [junit4]   2> 203306 T614 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-614]: publishFlushedSegment seg-private updates=null
   [junit4]   2> 203306 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: publishFlushedSegment
   [junit4]   2> 203306 T614 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-614]: push deletes  147 deleted terms (unique count=147) bytesUsed=1024 delGen=7 packetCount=1 totBytesUsed=1024
   [junit4]   2> 203306 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: publish sets newSegment delGen=8 seg=_1(4.8):C147
   [junit4]   2> 203310 T614 C100 oasu.LoggingInfoStream.message [IFD][qtp1222893950-614]: now checkpoint "_0(4.8):C253 _1(4.8):C147" [2 segments ; isCommit = false]
   [junit4]   2> 203310 T614 C100 oasu.LoggingInfoStream.message [IFD][qtp1222893950-614]: 0 msec to checkpoint
   [junit4]   2> 203310 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: apply all deletes during flush
   [junit4]   2> 203310 T614 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-614]: applyDeletes: infos=[_0(4.8):C253, _1(4.8):C147] packetCount=1
   [junit4]   2> 203310 T614 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-614]: seg=_0(4.8):C253 segGen=6 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericDVUpdates=0,binaryDVUpdates=0)] newDelCount=0
   [junit4]   2> 203312 T614 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-614]: applyDeletes took 2 msec
   [junit4]   2> 203312 T614 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-614]: prune sis=org.apache.lucene.index.SegmentInfos@7a79f279 minGen=9 packetCount=1
   [junit4]   2> 203312 T614 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-614]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 203315 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: return reader version=5 reader=StandardDirectoryReader(segments_2:5:nrt _0(4.8):C253 _1(4.8):C147)
   [junit4]   2> 203315 T614 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-614]: qtp1222893950-614 finishFullFlush success=true
   [junit4]   2> 203315 T614 C100 oasu.LoggingInfoStream.message [TMP][qtp1222893950-614]: findMerges: 2 segments
   [junit4]   2> 203315 T614 C100 oasu.LoggingInfoStream.message [TMP][qtp1222893950-614]:   seg=_0(4.8):C253 size=0.008 MB [floored]
   [junit4]   2> 203315 T614 C100 oasu.LoggingInfoStream.message [TMP][qtp1222893950-614]:   seg=_1(4.8):C147 size=0.005 MB [floored]
   [junit4]   2> 203318 T614 C100 oasu.LoggingInfoStream.message [TMP][qtp1222893950-614]:   allowedSegmentCount=1 vs count=2 (eligible count=2) tooBigCount=0
   [junit4]   2> 203318 T614 C100 oasu.LoggingInfoStream.message [CMS][qtp1222893950-614]: now merge
   [junit4]   2> 203318 T614 C100 oasu.LoggingInfoStream.message [CMS][qtp1222893950-614]:   index: _0(4.8):C253 _1(4.8):C147
   [junit4]   2> 203318 T614 C100 oasu.LoggingInfoStream.message [CMS][qtp1222893950-614]:   no more merges pending; now return
   [junit4]   2> 203318 T614 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-614]: getReader took 20 msec
   [junit4]   2> 203318 T614 C100 oass.SolrIndexSearcher.<init> Opening Searcher@442f8819[collection1] main
   [junit4]   2> 203322 T614 C100 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 203322 T610 C100 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 203323 T610 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-610]: commit: start
   [junit4]   2> 203323 T610 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-610]: commit: enter lock
   [junit4]   2> 203323 T610 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-610]: commit: now prepare
   [junit4]   2> 203323 T610 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-610]: prepareCommit: flush
   [junit4]   2> 203325 T610 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-610]:   index before flush _0(4.8):C253 _1(4.8):C147
   [junit4]   2> 203325 T610 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-610]: startFullFlush
   [junit4]   2> 203325 T610 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-610]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203325 T610 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-610]: apply all deletes during flush
   [junit4]   2> 203325 T610 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-610]: applyDeletes: no deletes; skipping
   [junit4]   2> 203325 T610 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-610]: prune sis=org.apache.lucene.index.SegmentInfos@7a79f279 minGen=9 packetCount=0
   [junit4]   2> 203325 T610 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-610]: qtp1222893950-610 finishFullFlush success=true
   [junit4]   2> 203325 T610 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-610]: startCommit(): start
   [junit4]   2> 203325 T610 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-610]: startCommit index=_0(4.8):C253 _1(4.8):C147 changeCount=6
   [junit4]   2> 203327 T610 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-610]: done all syncs: [_0_Lucene41_0.tip, _0_Lucene41_0.doc, _0.si, _0_Lucene41_0.tim, _1.si, _1.nvd, _0.nvd, _0.fdx, _1.nvm, _1.fnm, _0.fdt, _0_Lucene41_0.pos, _1_Lucene41_0.tip, _1.fdx, _1_Lucene41_0.doc, _1_Lucene41_0.tim, _0.nvm, _0.fnm, _1.fdt, _1_Lucene41_0.pos]
   [junit4]   2> 203327 T610 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-610]: commit: pendingCommit != null
   [junit4]   2> 203327 T610 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-610]: commit: wrote segments file "segments_3"
   [junit4]   2> 203328 T610 C100 oasu.LoggingInfoStream.message [IFD][qtp1222893950-610]: now checkpoint "_0(4.8):C253 _1(4.8):C147" [2 segments ; isCommit = true]
   [junit4]   2> 203330 T610 C100 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@6f731e20 lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\index),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@6f731e20 lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\index),segFN=segments_3,generation=3}
   [junit4]   2> 203330 T610 C100 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
   [junit4]   2> 203331 T610 C100 oasu.LoggingInfoStream.message [IFD][qtp1222893950-610]: deleteCommits: now decRef commit "segments_2"
   [junit4]   2> 203331 T610 C100 oasu.LoggingInfoStream.message [IFD][qtp1222893950-610]: delete "segments_2"
   [junit4]   2> 203331 T610 C100 oasu.LoggingInfoStream.message [IFD][qtp1222893950-610]: 2 msec to checkpoint
   [junit4]   2> 203332 T610 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-610]: commit: done
   [junit4]   2> 203332 T610 C100 oasc.SolrCore.getSearcher WARN [collection1] PERFORMANCE WARNING: Overlapping onDeckSearchers=2
   [junit4]   2> 203334 T610 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-610]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203334 T610 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-610]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
   [junit4]   2> 203335 T610 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-610]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203335 T610 C100 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 203335 T610 C100 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 203353 T612 C100 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[T0:0 (1464811478231023616), T0:1 (1464811478233120768), T0:2 (1464811478234169344), T0:3 (1464811478234169345), T0:4 (1464811478234169346), T0:5 (1464811478234169347), T0:6 (1464811478235217920), T0:7 (1464811478235217921), T0:8 (1464811478235217922), T0:9 (1464811478235217923), ... (100 adds)]} 0 15
   [junit4]   2> 203273 T611 C100 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[T4:0 (1464811478111485952), T4:1 (1464811478116728832), T4:2 (1464811478116728833), T4:3 (1464811478116728834), T4:4 (1464811478116728835), T4:5 (1464811478117777408), T4:6 (1464811478117777409), T4:7 (1464811478117777410), T4:8 (1464811478117777411), T4:9 (1464811478117777412), ... (100 adds)]} 0 49
   [junit4]   2> 203360 T611 C100 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 203360 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: commit: start
   [junit4]   2> 203360 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: commit: enter lock
   [junit4]   2> 203360 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: commit: now prepare
   [junit4]   2> 203360 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: prepareCommit: flush
   [junit4]   2> 203360 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]:   index before flush _0(4.8):C253 _1(4.8):C147
   [junit4]   2> 203360 T611 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-611]: startFullFlush
   [junit4]   2> 203363 T611 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-611]: anyChanges? numDocsInRam=100 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203363 T611 C100 oasu.LoggingInfoStream.message [DWFC][qtp1222893950-611]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 99 deleted terms (unique count=99) bytesUsed=23058, segment=_2, aborting=false, numDocsInRAM=100, deleteQueue=DWDQ: [ generation: 5 ]]
   [junit4]   2> 203363 T611 C100 oasu.LoggingInfoStream.message [DWPT][qtp1222893950-611]: flush postings as segment _2 numDocs=100
   [junit4]   2> 203367 T611 C100 oasu.LoggingInfoStream.message [DWPT][qtp1222893950-611]: new segment has 0 deleted docs
   [junit4]   2> 203367 T611 C100 oasu.LoggingInfoStream.message [DWPT][qtp1222893950-611]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 203367 T611 C100 oasu.LoggingInfoStream.message [DWPT][qtp1222893950-611]: 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> 203367 T611 C100 oasu.LoggingInfoStream.message [DWPT][qtp1222893950-611]: flushed codec=Lucene46
   [junit4]   2> 203367 T611 C100 oasu.LoggingInfoStream.message [DWPT][qtp1222893950-611]: flushed: segment=_2 ramUsed=0.099 MB newFlushedSize(includes docstores)=0.004 MB docs/MB=27,158.146
   [junit4]   2> 203367 T611 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-611]: publishFlushedSegment seg-private updates=null
   [junit4]   2> 203367 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: publishFlushedSegment
   [junit4]   2> 203367 T611 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-611]: push deletes  100 deleted terms (unique count=100) bytesUsed=1024 delGen=11 packetCount=1 totBytesUsed=1024
   [junit4]   2> 203367 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: publish sets newSegment delGen=12 seg=_2(4.8):C100
   [junit4]   2> 203368 T611 C100 oasu.LoggingInfoStream.message [IFD][qtp1222893950-611]: now checkpoint "_0(4.8):C253 _1(4.8):C147 _2(4.8):C100" [3 segments ; isCommit = false]
   [junit4]   2> 203370 T611 C100 oasu.LoggingInfoStream.message [IFD][qtp1222893950-611]: 2 msec to checkpoint
   [junit4]   2> 203371 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: apply all deletes during flush
   [junit4]   2> 203371 T611 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-611]: applyDeletes: infos=[_0(4.8):C253, _1(4.8):C147, _2(4.8):C100] packetCount=1
   [junit4]   2> 203371 T611 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-611]: seg=_1(4.8):C147 segGen=9 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericDVUpdates=0,binaryDVUpdates=0)] newDelCount=0
   [junit4]   2> 203371 T611 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-611]: seg=_0(4.8):C253 segGen=9 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericDVUpdates=0,binaryDVUpdates=0)] newDelCount=0
   [junit4]   2> 203371 T611 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-611]: applyDeletes took 0 msec
   [junit4]   2> 203371 T611 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-611]: prune sis=org.apache.lucene.index.SegmentInfos@7a79f279 minGen=13 packetCount=1
   [junit4]   2> 203371 T611 C100 oasu.LoggingInfoStream.message [BD][qtp1222893950-611]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 203371 T611 C100 oasu.LoggingInfoStream.message [DW][qtp1222893950-611]: qtp1222893950-611 finishFullFlush success=true
   [junit4]   2> 203371 T611 C100 oasu.LoggingInfoStream.message [TMP][qtp1222893950-611]: findMerges: 3 segments
   [junit4]   2> 203371 T611 C100 oasu.LoggingInfoStream.message [TMP][qtp1222893950-611]:   seg=_0(4.8):C253 size=0.008 MB [floored]
   [junit4]   2> 203371 T611 C100 oasu.LoggingInfoStream.message [TMP][qtp1222893950-611]:   seg=_1(4.8):C147 size=0.005 MB [floored]
   [junit4]   2> 203375 T611 C100 oasu.LoggingInfoStream.message [TMP][qtp1222893950-611]:   seg=_2(4.8):C100 size=0.004 MB [floored]
   [junit4]   2> 203375 T611 C100 oasu.LoggingInfoStream.message [TMP][qtp1222893950-611]:   allowedSegmentCount=1 vs count=3 (eligible count=3) tooBigCount=0
   [junit4]   2> 203376 T611 C100 oasu.LoggingInfoStream.message [CMS][qtp1222893950-611]: now merge
   [junit4]   2> 203376 T611 C100 oasu.LoggingInfoStream.message [CMS][qtp1222893950-611]:   index: _0(4.8):C253 _1(4.8):C147 _2(4.8):C100
   [junit4]   2> 203376 T611 C100 oasu.LoggingInfoStream.message [CMS][qtp1222893950-611]:   no more merges pending; now return
   [junit4]   2> 203376 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: startCommit(): start
   [junit4]   2> 203376 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: startCommit index=_0(4.8):C253 _1(4.8):C147 _2(4.8):C100 changeCount=9
   [junit4]   2> 203376 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: done all syncs: [_0_Lucene41_0.tip, _0_Lucene41_0.tim, _1.si, _1.nvd, _0.nvd, _2.fdt, _2_Lucene41_0.doc, _1.nvm, _1.fnm, _2.fdx, _0_Lucene41_0.pos, _2.nvd, _2.nvm, _2.fnm, _1.fdx, _1_Lucene41_0.doc, _1.fdt, _0_Lucene41_0.doc, _0.si, _2.si, _2_Lucene41_0.tip, _2_Lucene41_0.tim, _0.fdx, _2_Lucene41_0.pos, _0.fdt, _1_Lucene41_0.tip, _1_Lucene41_0.tim, _0.nvm, _0.fnm, _1_Lucene41_0.pos]
   [junit4]   2> 203376 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: commit: pendingCommit != null
   [junit4]   2> 203376 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: commit: wrote segments file "segments_4"
   [junit4]   2> 203377 T611 C100 oasu.LoggingInfoStream.message [IFD][qtp1222893950-611]: now checkpoint "_0(4.8):C253 _1(4.8):C147 _2(4.8):C100" [3 segments ; isCommit = true]
   [junit4]   2> 203379 T611 C100 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@6f731e20 lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\index),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@6f731e20 lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\index),segFN=segments_4,generation=4}
   [junit4]   2> 203379 T611 C100 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
   [junit4]   2> 203379 T611 C100 oasu.LoggingInfoStream.message [IFD][qtp1222893950-611]: deleteCommits: now decRef commit "segments_3"
   [junit4]   2> 203379 T611 C100 oasu.LoggingInfoStream.message [IFD][qtp1222893950-611]: delete "segments_3"
   [junit4]   2> 203379 T611 C100 oasu.LoggingInfoStream.message [IFD][qtp1222893950-611]: 2 msec to checkpoint
   [junit4]   2> 203381 T611 C100 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: commit: done
   [junit4]   2> 203381 T611 C100 oasc.SolrCore.getSearcher WARN [collection1] Error opening new searcher. exceeded limit of maxWarmingSearchers=2, try again later.
   [junit4]   2> 203381 T611 C100 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} {} 0 22
   [junit4]   2> 203381 T611 C100 oasc.SolrException.log Ignoring exception matching maxWarmingSearchers
   [junit4]   2> 203384 T620 oascs.LargeVolumeTestBase$DocThread.run Caught benign exception during commit: Error opening new searcher. exceeded limit of maxWarmingSearchers=2, try again later.
   [junit4]   2> 203388 T611 C100 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> ASYNC  NEW_CORE C101 name=collection1 org.apache.solr.core.SolrCore@1a56020
   [junit4]   2> 203388 T611 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-611]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203401 T611 C101 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 203401 T611 C101 oasc.SolrCore.getSearcher WARN [collection1] Error opening new searcher. exceeded limit of maxWarmingSearchers=2, try again later.
   [junit4]   2> 203401 T611 C101 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} {} 0 13
   [junit4]   2> 203403 T611 C101 oasc.SolrException.log Ignoring exception matching maxWarmingSearchers
   [junit4]   2> 203404 T624 oascs.LargeVolumeTestBase$DocThread.run Caught benign exception during commit: Error opening new searcher. exceeded limit of maxWarmingSearchers=2, try again later.
   [junit4]   2> 203266 T613 C101 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[T3:0 (1464811478050668544), T3:1 (1464811478141894656), T3:2 (1464811478142943232), T3:3 (1464811478145040384), T3:4 (1464811478145040385), T3:5 (1464811478145040386), T3:6 (1464811478145040387), T3:7 (1464811478145040388), T3:8 (1464811478145040389), T3:9 (1464811478145040390), ... (100 adds)]} 0 101
   [junit4]   2> 203400 T617 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@442f8819[collection1] main{StandardDirectoryReader(segments_2:5:nrt _0(4.8):C253 _1(4.8):C147)}
   [junit4]   2> 203407 T617 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 203407 T617 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@442f8819[collection1] main{StandardDirectoryReader(segments_2:5:nrt _0(4.8):C253 _1(4.8):C147)}
   [junit4]   2> 203410 T617 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@442f8819[collection1] main{StandardDirectoryReader(segments_2:5:nrt _0(4.8):C253 _1(4.8):C147)}
   [junit4]   2> 203410 T617 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 203411 T614 C101 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} {commit=} 0 198
   [junit4]   2> 203412 T610 C101 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} {commit=} 0 189
   [junit4]   2> 203415 T615 C101 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 203415 T615 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-615]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203415 T615 C101 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 203415 T615 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-615]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203415 T615 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-615]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
   [junit4]   2> 203415 T615 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-615]: flush at getReader
   [junit4]   2> 203415 T615 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-615]: startFullFlush
   [junit4]   2> 203415 T615 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-615]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203415 T615 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-615]: apply all deletes during flush
   [junit4]   2> 203419 T615 C101 oasu.LoggingInfoStream.message [BD][qtp1222893950-615]: applyDeletes: no deletes; skipping
   [junit4]   2> 203419 T615 C101 oasu.LoggingInfoStream.message [BD][qtp1222893950-615]: prune sis=org.apache.lucene.index.SegmentInfos@7a79f279 minGen=13 packetCount=0
   [junit4]   2> 203420 T615 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-615]: return reader version=7 reader=StandardDirectoryReader(segments_4:7:nrt _0(4.8):C253 _1(4.8):C147 _2(4.8):C100)
   [junit4]   2> 203420 T615 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-615]: qtp1222893950-615 finishFullFlush success=true
   [junit4]   2> 203420 T615 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-615]: getReader took 5 msec
   [junit4]   2> 203420 T615 C101 oass.SolrIndexSearcher.<init> Opening Searcher@6f5feb3e[collection1] main
   [junit4]   2> 203420 T615 C101 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 203421 T612 C101 oasu.DirectUpdateHandler2.commit start commit{,optimize=true,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 203422 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: forceMerge: index now _0(4.8):C253 _1(4.8):C147 _2(4.8):C100
   [junit4]   2> 203422 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: now flush at forceMerge
   [junit4]   2> 203422 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]:   start flush: applyAllDeletes=true
   [junit4]   2> 203422 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]:   index before flush _0(4.8):C253 _1(4.8):C147 _2(4.8):C100
   [junit4]   2> 203422 T612 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-612]: startFullFlush
   [junit4]   2> 203422 T612 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-612]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203422 T612 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-612]: qtp1222893950-612 finishFullFlush success=true
   [junit4]   2> 203425 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: apply all deletes during flush
   [junit4]   2> 203425 T612 C101 oasu.LoggingInfoStream.message [BD][qtp1222893950-612]: applyDeletes: no deletes; skipping
   [junit4]   2> 203425 T612 C101 oasu.LoggingInfoStream.message [BD][qtp1222893950-612]: prune sis=org.apache.lucene.index.SegmentInfos@7a79f279 minGen=13 packetCount=0
   [junit4]   2> 203425 T612 C101 oasu.LoggingInfoStream.message [TMP][qtp1222893950-612]: findForcedMerges maxSegmentCount=1 infos=_0(4.8):C253 _1(4.8):C147 _2(4.8):C100 segmentsToMerge={_1(4.8):C147=true, _2(4.8):C100=true, _0(4.8):C253=true}
   [junit4]   2> 203425 T612 C101 oasu.LoggingInfoStream.message [TMP][qtp1222893950-612]: eligible=[_0(4.8):C253, _1(4.8):C147, _2(4.8):C100]
   [junit4]   2> 203426 T612 C101 oasu.LoggingInfoStream.message [TMP][qtp1222893950-612]: forceMergeRunning=false
   [junit4]   2> 203427 T612 C101 oasu.LoggingInfoStream.message [TMP][qtp1222893950-612]: add final merge=_0(4.8):C253 _1(4.8):C147 _2(4.8):C100
   [junit4]   2> 203427 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: add merge to pendingMerges: _0(4.8):C253 _1(4.8):C147 _2(4.8):C100 [total 1 pending]
   [junit4]   2> 203427 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: registerMerge merging= []
   [junit4]   2> 203427 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: registerMerge info=_0(4.8):C253
   [junit4]   2> 203427 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: registerMerge info=_1(4.8):C147
   [junit4]   2> 203427 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: registerMerge info=_2(4.8):C100
   [junit4]   2> 203427 T612 C101 oasu.LoggingInfoStream.message [CMS][qtp1222893950-612]: now merge
   [junit4]   2> 203427 T612 C101 oasu.LoggingInfoStream.message [CMS][qtp1222893950-612]:   index: _0(4.8):C253 _1(4.8):C147 _2(4.8):C100
   [junit4]   2> 203427 T612 C101 oasu.LoggingInfoStream.message [CMS][qtp1222893950-612]:   consider merge _0(4.8):C253 _1(4.8):C147 _2(4.8):C100
   [junit4]   2> 203427 T612 C101 oasu.LoggingInfoStream.message [CMS][qtp1222893950-612]:     launch new thread [Lucene Merge Thread #0]
   [junit4]   2> 203430 T612 C101 oasu.LoggingInfoStream.message [CMS][qtp1222893950-612]: set priority of merge thread Lucene Merge Thread #0 to 6
   [junit4]   2> 203430 T612 C101 oasu.LoggingInfoStream.message [CMS][qtp1222893950-612]:   no more merges pending; now return
   [junit4]   2> 203432 T617 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@6f5feb3e[collection1] main{StandardDirectoryReader(segments_4:7:nrt _0(4.8):C253 _1(4.8):C147 _2(4.8):C100)}
   [junit4]   2> 203432 T617 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 203432 T617 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6f5feb3e[collection1] main{StandardDirectoryReader(segments_4:7:nrt _0(4.8):C253 _1(4.8):C147 _2(4.8):C100)}
   [junit4]   2> 203435 T615 C101 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} {commit=} 0 21
   [junit4]   2> 203440 T625 oasu.LoggingInfoStream.message [CMS][Lucene Merge Thread #0]:   merge thread: start
   [junit4]   2> 203441 T625 oasu.LoggingInfoStream.message [BD][Lucene Merge Thread #0]: applyDeletes: no deletes; skipping
   [junit4]   2> 203441 T625 oasu.LoggingInfoStream.message [BD][Lucene Merge Thread #0]: prune sis=org.apache.lucene.index.SegmentInfos@7a79f279 minGen=13 packetCount=0
   [junit4]   2> 203441 T625 oasu.LoggingInfoStream.message [IW][Lucene Merge Thread #0]: merge seg=_3 _0(4.8):C253 _1(4.8):C147 _2(4.8):C100
   [junit4]   2> 203441 T625 oasu.LoggingInfoStream.message [IW][Lucene Merge Thread #0]: now merge
   [junit4]   2> 	  merge=_0(4.8):C253 _1(4.8):C147 _2(4.8):C100
   [junit4]   2> 	  index=_0(4.8):C253 _1(4.8):C147 _2(4.8):C100
   [junit4]   2> 203441 T625 oasu.LoggingInfoStream.message [IW][Lucene Merge Thread #0]: merging _0(4.8):C253 _1(4.8):C147 _2(4.8):C100
   [junit4]   2> 203441 T625 oasu.LoggingInfoStream.message [IW][Lucene Merge Thread #0]: seg=_0(4.8):C253 no deletes
   [junit4]   2> 203441 T625 oasu.LoggingInfoStream.message [IW][Lucene Merge Thread #0]: seg=_1(4.8):C147 no deletes
   [junit4]   2> 203441 T625 oasu.LoggingInfoStream.message [IW][Lucene Merge Thread #0]: seg=_2(4.8):C100 no deletes
   [junit4]   2> 203441 T625 oasu.LoggingInfoStream.message [SM][Lucene Merge Thread #0]: merge store matchedCount=3 vs 3
   [junit4]   2> 203442 T625 oasu.LoggingInfoStream.message [SM][Lucene Merge Thread #0]: 0 msec to merge stored fields [500 docs]
   [junit4]   2> 203450 T625 oasu.LoggingInfoStream.message [SM][Lucene Merge Thread #0]: 5 msec to merge postings [500 docs]
   [junit4]   2> 203450 T625 oasu.LoggingInfoStream.message [SM][Lucene Merge Thread #0]: 0 msec to merge doc values [500 docs]
   [junit4]   2> 203450 T625 oasu.LoggingInfoStream.message [SM][Lucene Merge Thread #0]: 0 msec to merge norms [500 docs]
   [junit4]   2> 203451 T625 oasu.LoggingInfoStream.message [IW][Lucene Merge Thread #0]: merge codec=Lucene46 docCount=500; merged segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 203451 T625 oasu.LoggingInfoStream.message [IW][Lucene Merge Thread #0]: merged segment size=0.014 MB vs estimate=0.017 MB
   [junit4]   2> 203451 T625 oasu.LoggingInfoStream.message [IW][Lucene Merge Thread #0]: commitMerge: _0(4.8):C253 _1(4.8):C147 _2(4.8):C100 index=_0(4.8):C253 _1(4.8):C147 _2(4.8):C100
   [junit4]   2> 203451 T625 oasu.LoggingInfoStream.message [IW][Lucene Merge Thread #0]: commitMergeDeletes _0(4.8):C253 _1(4.8):C147 _2(4.8):C100
   [junit4]   2> 203452 T625 oasu.LoggingInfoStream.message [IW][Lucene Merge Thread #0]: no new deletes or field updates since merge started
   [junit4]   2> 203452 T625 oasu.LoggingInfoStream.message [IFD][Lucene Merge Thread #0]: now checkpoint "_3(4.8):C500" [1 segments ; isCommit = false]
   [junit4]   2> 203452 T625 oasu.LoggingInfoStream.message [IFD][Lucene Merge Thread #0]: 0 msec to checkpoint
   [junit4]   2> 203452 T625 oasu.LoggingInfoStream.message [IW][Lucene Merge Thread #0]: after commitMerge: _3(4.8):C500
   [junit4]   2> 203452 T625 oasu.LoggingInfoStream.message [TMP][Lucene Merge Thread #0]: findForcedMerges maxSegmentCount=1 infos=_3(4.8):C500 segmentsToMerge={_1(4.8):C147=true, _3(4.8):C500=false, _2(4.8):C100=true, _0(4.8):C253=true}
   [junit4]   2> 203452 T625 oasu.LoggingInfoStream.message [TMP][Lucene Merge Thread #0]: already merged
   [junit4]   2> 203452 T625 oasu.LoggingInfoStream.message [IW][Lucene Merge Thread #0]: merge time 11 msec for 500 docs
   [junit4]   2> 203452 T625 oasu.LoggingInfoStream.message [CMS][Lucene Merge Thread #0]:   merge thread: done
   [junit4]   2> 203455 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: commit: start
   [junit4]   2> 203456 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: commit: enter lock
   [junit4]   2> 203456 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: commit: now prepare
   [junit4]   2> 203456 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: prepareCommit: flush
   [junit4]   2> 203456 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]:   index before flush _3(4.8):C500
   [junit4]   2> 203456 T612 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-612]: startFullFlush
   [junit4]   2> 203456 T612 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-612]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203456 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: apply all deletes during flush
   [junit4]   2> 203456 T612 C101 oasu.LoggingInfoStream.message [BD][qtp1222893950-612]: applyDeletes: no deletes; skipping
   [junit4]   2> 203459 T612 C101 oasu.LoggingInfoStream.message [BD][qtp1222893950-612]: prune sis=org.apache.lucene.index.SegmentInfos@7a79f279 minGen=13 packetCount=0
   [junit4]   2> 203459 T612 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-612]: qtp1222893950-612 finishFullFlush success=true
   [junit4]   2> 203459 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: startCommit(): start
   [junit4]   2> 203459 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: startCommit index=_3(4.8):C500 changeCount=12
   [junit4]   2> 203462 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: done all syncs: [_3.fdx, _3_Lucene41_0.pos, _3.si, _3.nvd, _3_Lucene41_0.doc, _3_Lucene41_0.tim, _3_Lucene41_0.tip, _3.nvm, _3.fnm, _3.fdt]
   [junit4]   2> 203462 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: commit: pendingCommit != null
   [junit4]   2> 203462 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: commit: wrote segments file "segments_5"
   [junit4]   2> 203463 T612 C101 oasu.LoggingInfoStream.message [IFD][qtp1222893950-612]: now checkpoint "_3(4.8):C500" [1 segments ; isCommit = true]
   [junit4]   2> 203464 T612 C101 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@6f731e20 lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\index),segFN=segments_4,generation=4}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@6f731e20 lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\index),segFN=segments_5,generation=5}
   [junit4]   2> 203464 T612 C101 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
   [junit4]   2> 203465 T612 C101 oasu.LoggingInfoStream.message [IFD][qtp1222893950-612]: deleteCommits: now decRef commit "segments_4"
   [junit4]   2> 203465 T612 C101 oasu.LoggingInfoStream.message [IFD][qtp1222893950-612]: delete "segments_4"
   [junit4]   2> 203466 T612 C101 oasu.LoggingInfoStream.message [IFD][qtp1222893950-612]: 2 msec to checkpoint
   [junit4]   2> 203466 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: commit: done
   [junit4]   2> 203466 T612 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-612]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203466 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
   [junit4]   2> 203466 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: flush at getReader
   [junit4]   2> 203470 T612 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-612]: startFullFlush
   [junit4]   2> 203470 T612 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-612]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203470 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: apply all deletes during flush
   [junit4]   2> 203470 T612 C101 oasu.LoggingInfoStream.message [BD][qtp1222893950-612]: applyDeletes: no deletes; skipping
   [junit4]   2> 203470 T612 C101 oasu.LoggingInfoStream.message [BD][qtp1222893950-612]: prune sis=org.apache.lucene.index.SegmentInfos@7a79f279 minGen=13 packetCount=0
   [junit4]   2> 203470 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: return reader version=9 reader=StandardDirectoryReader(segments_5:9:nrt _3(4.8):C500)
   [junit4]   2> 203471 T612 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-612]: qtp1222893950-612 finishFullFlush success=true
   [junit4]   2> 203473 T612 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-612]: getReader took 7 msec
   [junit4]   2> 203473 T612 C101 oass.SolrIndexSearcher.<init> Opening Searcher@3be6b7c8[collection1] main
   [junit4]   2> 203473 T612 C101 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 203477 T617 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@3be6b7c8[collection1] main{StandardDirectoryReader(segments_5:9:nrt _3(4.8):C500)}
   [junit4]   2> 203477 T617 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 203479 T617 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3be6b7c8[collection1] main{StandardDirectoryReader(segments_5:9:nrt _3(4.8):C500)}
   [junit4]   2> 203479 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_0_Lucene41_0.tip"
   [junit4]   2> 203479 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_0_Lucene41_0.tim"
   [junit4]   2> 203479 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_1.si"
   [junit4]   2> 203481 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_1.nvd"
   [junit4]   2> 203481 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_0.nvd"
   [junit4]   2> 203481 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_2.fdt"
   [junit4]   2> 203481 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_2_Lucene41_0.doc"
   [junit4]   2> 203481 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_1.nvm"
   [junit4]   2> 203481 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_1.fnm"
   [junit4]   2> 203483 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_2.fdx"
   [junit4]   2> 203484 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_0_Lucene41_0.pos"
   [junit4]   2> 203484 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_2.nvd"
   [junit4]   2> 203484 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_2.nvm"
   [junit4]   2> 203484 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_2.fnm"
   [junit4]   2> 203484 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_1.fdx"
   [junit4]   2> 203484 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_1_Lucene41_0.doc"
   [junit4]   2> 203484 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_1.fdt"
   [junit4]   2> 203484 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_0_Lucene41_0.doc"
   [junit4]   2> 203486 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_0.si"
   [junit4]   2> 203486 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_2.si"
   [junit4]   2> 203486 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_2_Lucene41_0.tip"
   [junit4]   2> 203486 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_2_Lucene41_0.tim"
   [junit4]   2> 203486 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_0.fdx"
   [junit4]   2> 203486 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_2_Lucene41_0.pos"
   [junit4]   2> 203486 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_0.fdt"
   [junit4]   2> 203486 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_1_Lucene41_0.tip"
   [junit4]   2> 203488 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_1_Lucene41_0.tim"
   [junit4]   2> 203488 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_0.nvm"
   [junit4]   2> 203488 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_0.fnm"
   [junit4]   2> 203488 T617 oasu.LoggingInfoStream.message [IFD][searcherExecutor-340-thread-1]: delete "_1_Lucene41_0.pos"
   [junit4]   2> 203489 T612 C101 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={optimize=true&maxSegments=1&waitSearcher=true&wt=javabin&version=2} {optimize=} 0 70
   [junit4]   2> 203494 T611 C101 oasu.DirectUpdateHandler2.commit start commit{,optimize=true,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 203494 T611 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: forceMerge: index now _3(4.8):C500
   [junit4]   2> 203494 T611 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: now flush at forceMerge
   [junit4]   2> 203494 T611 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]:   start flush: applyAllDeletes=true
   [junit4]   2> 203494 T611 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]:   index before flush _3(4.8):C500
   [junit4]   2> 203494 T611 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-611]: startFullFlush
   [junit4]   2> 203494 T611 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-611]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203498 T611 C101 oasu.LoggingInfoStream.message [DW][qtp1222893950-611]: qtp1222893950-611 finishFullFlush success=true
   [junit4]   2> 203498 T611 C101 oasu.LoggingInfoStream.message [IW][qtp1222893950-611]: apply all deletes during flush
   [junit4]   2> 203498 T611 C101 oasu.LoggingInfoStream.message [BD][qtp1222893950-611]: applyDeletes: no deletes; skipping
   [junit4]   2> 203498 T611 C101 oasu.LoggingInfoStream.message [BD][qtp1222893950-611]: prune sis=org.apache.lucene.index.SegmentInfos@7a79f279 minGen=13 packetCount=0
   [junit4]   2> 203498 T611 C101 oasu.LoggingInfoStream.message [TMP][qtp1222893950-611]: findForcedMerges maxSegmentCount=1 infos=_3(4.8):C500 segmentsToMerge={_3(4.8):C500=true}
   [junit4]   2> 203498 T611 C101 oasu.LoggingInfoStream.message [TMP][qtp1222893950-611]: already merged
   [junit4]   2> 203500 T611 C101 oasu.LoggingInfoStream.message [CMS][qtp1222893950-611]: now merge
   [junit4]   2> 203501 T611 C101 oasu.LoggingInfoStream.message [CMS][qtp1222893950-611]:   index: _3(4.8):C500
   [junit4]   2> 203501 T611 C101 oasu.LoggingInfoStream.message [CMS][qtp1222893950-611]:   no more merges 

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

tream.message [DW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker finishFullFlush success=true
   [junit4]   2> 203582 T606 C101 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: apply all deletes during flush
   [junit4]   2> 203582 T606 C101 oasu.LoggingInfoStream.message [BD][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: applyDeletes: no deletes; skipping
   [junit4]   2> 203582 T606 C101 oasu.LoggingInfoStream.message [BD][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@7a79f279 minGen=13 packetCount=0
   [junit4]   2> 203582 T606 C101 oasu.LoggingInfoStream.message [CMS][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: now merge
   [junit4]   2> 203582 T606 C101 oasu.LoggingInfoStream.message [CMS][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]:   index: _3(4.8):C500
   [junit4]   2> 203582 T606 C101 oasu.LoggingInfoStream.message [CMS][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]:   no more merges pending; now return
   [junit4]   2> 203587 T606 C101 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: waitForMerges
   [junit4]   2> 203587 T606 C101 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: waitForMerges done
   [junit4]   2> 203587 T606 C101 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: now call final commit()
   [junit4]   2> 203587 T606 C101 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: commit: start
   [junit4]   2> 203587 T606 C101 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: commit: enter lock
   [junit4]   2> 203587 T606 C101 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: commit: now prepare
   [junit4]   2> 203587 T606 C101 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: prepareCommit: flush
   [junit4]   2> 203587 T606 C101 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]:   index before flush _3(4.8):C500
   [junit4]   2> 203587 T606 C101 oasu.LoggingInfoStream.message [DW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: startFullFlush
   [junit4]   2> 203590 T606 C101 oasu.LoggingInfoStream.message [DW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 203590 T606 C101 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: apply all deletes during flush
   [junit4]   2> 203590 T606 C101 oasu.LoggingInfoStream.message [BD][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: applyDeletes: no deletes; skipping
   [junit4]   2> 203590 T606 C101 oasu.LoggingInfoStream.message [BD][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@7a79f279 minGen=13 packetCount=0
   [junit4]   2> 203593 T606 C101 oasu.LoggingInfoStream.message [DW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker finishFullFlush success=true
   [junit4]   2> 203593 T606 C101 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: startCommit(): start
   [junit4]   2> 203593 T606 C101 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]:   skip startCommit(): no changes pending
   [junit4]   2> 203593 T606 C101 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: commit: pendingCommit == null; skip
   [junit4]   2> 203593 T606 C101 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: commit: done
   [junit4]   2> 203593 T606 C101 oasu.LoggingInfoStream.message [IW][SUITE-LargeVolumeJettyTest-seed#[EA97E28109CE696]-worker]: at close: _3(4.8):C500
   [junit4]   2> 203625 T606 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 203625 T606 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 203625 T606 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.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-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.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\index;done=false>>]
   [junit4]   2> 203625 T606 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\index
   [junit4]   2> 203626 T606 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.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\;done=false>>]
   [junit4]   2> 203626 T606 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\
   [junit4]   2> 203627 T606 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 203681 T606 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene40, sim=DefaultSimilarity, locale=mt, timezone=America/Regina
   [junit4]   2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.8.0_20-ea (64-bit)/cpus=2,threads=1,free=149854032,total=217055232
   [junit4]   2> NOTE: All tests run in this JVM: [SolrExampleBinaryTest, SolrExampleStreamingTest, LargeVolumeBinaryJettyTest, TestEmbeddedSolrServer, MultiCoreExampleJettyTest, CloudSolrServerTest, TestXMLEscaping, JettyWebappTest, IteratorChainTest, TestFastInputStream, TestLBHttpSolrServer, SolrExampleXMLTest, TestBatchUpdate, TestSpellCheckResponse, SolrExampleStreamingBinaryTest, SolrQueryTest, SolrDocumentTest, FacetFieldTest, LargeVolumeEmbeddedTest, TestCoreAdmin, ModifiableSolrParamsTest, TermsResponseTest, TestHash, SolrExampleEmbeddedTest, SolrExampleJettyTest, BasicHttpSolrServerTest, LargeVolumeJettyTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=LargeVolumeJettyTest -Dtests.seed=EA97E28109CE696 -Dtests.slow=true -Dtests.locale=mt -Dtests.timezone=America/Regina -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   0.00s | LargeVolumeJettyTest (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.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\tlog\tlog.0000000000000000002
   [junit4]    >    C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001\tlog
   [junit4]    >    C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001\tempDir-001
   [junit4]    >    C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solr.client.solrj.embedded.LargeVolumeJettyTest-EA97E28109CE696-001
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([EA97E28109CE696]:0)
   [junit4]    > 	at org.apache.lucene.util.TestUtil.rm(TestUtil.java:118)
   [junit4]    > 	at org.apache.lucene.util.LuceneTestCase$TemporaryFilesCleanupRule.afterAlways(LuceneTestCase.java:2387)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:744)
   [junit4] Completed in 1.44s, 1 test, 1 error <<< FAILURES!

[...truncated 72 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:447: 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:1282: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:908: There were test failures: 49 suites, 284 tests, 1 suite-level error

Total time: 91 minutes 44 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0_20-ea-b05 -XX:-UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message