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-trunk-Windows (64bit/jdk1.8.0-ea-b102) - Build # 3243 - Failure!
Date Tue, 10 Sep 2013 21:38:18 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/3243/
Java: 64bit/jdk1.8.0-ea-b102 -XX:+UseCompressedOops -XX:+UseParallelGC

1 tests failed.
REGRESSION:  org.apache.solr.client.solrj.SolrExampleBinaryTest.testStatistics

Error Message:
IOException occured when talking to server at: https://127.0.0.1:52890/solr/collection1

Stack Trace:
org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:52890/solr/collection1
	at __randomizedtesting.SeedInfo.seed([6C5A4F226687798E:9BF37C46CAAAA366]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:436)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
	at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:168)
	at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:146)
	at org.apache.solr.client.solrj.SolrExampleTests.testStatistics(SolrExampleTests.java:804)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:491)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	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:358)
	at java.lang.Thread.run(Thread.java:724)
Caused by: org.apache.http.NoHttpResponseException: The target server failed to respond
	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:95)
	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:62)
	at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:254)
	at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:289)
	at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:252)
	at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:191)
	at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
	at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
	at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:717)
	at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:522)
	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
	... 45 more




Build Log:
[...truncated 10841 lines...]
   [junit4] Suite: org.apache.solr.client.solrj.SolrExampleBinaryTest
   [junit4]   2> 3283 T17 oas.SolrJettyTestBase.beforeSolrJettyTestBase Randomized ssl (true) and clientAuth (false)
   [junit4]   2> 3283 T17 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\.\solrtest-SolrExampleBinaryTest-1378848681449
   [junit4]   2> 3285 T17 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 3824 T17 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 4345 T17 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 4398 T17 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:52890
   [junit4]   2> 4462 T17 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 4464 T17 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 4464 T17 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr
   [junit4]   2> 4465 T17 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\'
   [junit4]   2> 4530 T17 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\solr.xml
   [junit4]   2> 5062 T17 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 5094 T17 oasc.CoreContainer.<init> New CoreContainer 1314241569
   [junit4]   2> 5095 T17 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\]
   [junit4]   2> 5227 T17 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 5228 T17 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 5228 T17 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 5230 T17 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 5231 T17 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 5231 T17 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 5232 T17 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 5232 T17 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 5233 T17 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 5263 T17 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
   [junit4]   2> 5553 T17 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 5559 T17 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 6213 T17 oasc.CorePropertiesLocator.discover Looking for core definitions underneath C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr
   [junit4]   2> 6394 T17 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\
   [junit4]   2> 6396 T17 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 6406 T29 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1
   [junit4]   2> 6408 T29 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\'
   [junit4]   2> 6557 T29 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
   [junit4]   2> 6561 T29 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/extraction/lib (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\..\..\..\contrib\extraction\lib).
   [junit4]   2> 6563 T29 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\..\..\..\dist).
   [junit4]   2> 6564 T29 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/clustering/lib/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\..\..\..\contrib\clustering\lib).
   [junit4]   2> 6565 T29 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\..\..\..\dist).
   [junit4]   2> 6566 T29 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/langid/lib/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\..\..\..\contrib\langid\lib).
   [junit4]   2> 6566 T29 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\..\..\..\dist).
   [junit4]   2> 6568 T29 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/velocity/lib (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\..\..\..\contrib\velocity\lib).
   [junit4]   2> 6568 T29 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\..\..\..\dist).
   [junit4]   2> 6631 T29 oasu.SolrIndexConfig.<init> IndexWriter infoStream solr logging is enabled
   [junit4]   2> 6635 T29 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 6897 T29 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 6934 T29 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 7089 T29 oass.IndexSchema.readSchema [null] Schema name=example
   [junit4]   2> 8641 T29 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 9282 T29 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 9293 T29 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 9652 T29 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 9688 T29 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleBinaryTest-1378848681449\
   [junit4]   2> 9695 T29 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@412ba7f9
   [junit4]   2> 9752 T29 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
   [junit4]   2> 9753 T29 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
   [junit4]   2> 9889 T29 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleBinaryTest-1378848681449\
   [junit4]   2> 9891 T29 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleBinaryTest-1378848681449\index/
   [junit4]   2> 9892 T29 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleBinaryTest-1378848681449\index' doesn't exist. Creating new index...
   [junit4]   2> 9923 T29 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleBinaryTest-1378848681449\index
   [junit4]   2> 10073 T29 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-3-thread-1]: init: current segments file is "null"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@6c91f037
   [junit4]   2> 10079 T29 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-3-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 10080 T29 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-3-thread-1]: 0 msec to checkpoint
   [junit4]   2> 10080 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: init: create=true
   [junit4]   2> 10081 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: 
   [junit4]   2> 	dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@60590c33 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e67797a)
   [junit4]   2> 	index=
   [junit4]   2> 	version=5.0-SNAPSHOT
   [junit4]   2> 	matchVersion=LUCENE_50
   [junit4]   2> 	analyzer=null
   [junit4]   2> 	ramBufferSizeMB=100.0
   [junit4]   2> 	maxBufferedDocs=-1
   [junit4]   2> 	maxBufferedDeleteTerms=-1
   [junit4]   2> 	mergedSegmentWarmer=null
   [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=Lucene45
   [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@74dee6f8
   [junit4]   2> 	readerPooling=false
   [junit4]   2> 	perThreadHardLimitMB=1945
   [junit4]   2> 	useCompoundFile=false
   [junit4]   2> 	
   [junit4]   2> 10081 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: now flush at close waitForMerges=true
   [junit4]   2> 10082 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]:   start flush: applyAllDeletes=true
   [junit4]   2> 10082 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]:   index before flush 
   [junit4]   2> 10082 T29 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-3-thread-1]: coreLoadExecutor-3-thread-1 startFullFlush
   [junit4]   2> 10083 T29 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-3-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 10084 T29 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-3-thread-1]: coreLoadExecutor-3-thread-1 finishFullFlush success=true
   [junit4]   2> 10084 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: apply all deletes during flush
   [junit4]   2> 10090 T29 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-3-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@57c6872a minGen=9223372036854775807 packetCount=0
   [junit4]   2> 10090 T29 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-3-thread-1]: now merge
   [junit4]   2> 10091 T29 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-3-thread-1]:   index: 
   [junit4]   2> 10091 T29 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-3-thread-1]:   no more merges pending; now return
   [junit4]   2> 10091 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: waitForMerges
   [junit4]   2> 10092 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: waitForMerges done
   [junit4]   2> 10093 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: now call final commit()
   [junit4]   2> 10093 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: commit: start
   [junit4]   2> 10093 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: commit: enter lock
   [junit4]   2> 10093 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: commit: now prepare
   [junit4]   2> 10094 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: prepareCommit: flush
   [junit4]   2> 10094 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]:   index before flush 
   [junit4]   2> 10094 T29 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-3-thread-1]: coreLoadExecutor-3-thread-1 startFullFlush
   [junit4]   2> 10094 T29 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-3-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 10094 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: apply all deletes during flush
   [junit4]   2> 10095 T29 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-3-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@57c6872a minGen=9223372036854775807 packetCount=0
   [junit4]   2> 10096 T29 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-3-thread-1]: coreLoadExecutor-3-thread-1 finishFullFlush success=true
   [junit4]   2> 10096 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: startCommit(): start
   [junit4]   2> 10097 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: startCommit index= changeCount=1
   [junit4]   2> 10157 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: done all syncs: []
   [junit4]   2> 10157 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: commit: pendingCommit != null
   [junit4]   2> 10158 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: commit: wrote segments file "segments_1"
   [junit4]   2> 10158 T29 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-3-thread-1]: now checkpoint "" [0 segments ; isCommit = true]
   [junit4]   2> 10176 T29 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@60590c33 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e67797a),segFN=segments_1,generation=1}
   [junit4]   2> 10180 T29 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 10180 T29 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-3-thread-1]: 21 msec to checkpoint
   [junit4]   2> 10181 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: commit: done
   [junit4]   2> 10181 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: at close: 
   [junit4]   2> 10216 T29 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
   [junit4]   2> 10217 T29 oasc.SolrCore.initWriters adding lazy queryResponseWriter: solr.VelocityResponseWriter
   [junit4]   2> 10222 T29 oasc.SolrCore.initWriters created velocity: solr.VelocityResponseWriter
   [junit4]   2> 10263 T29 oasc.SolrCore.initWriters created xslt: solr.XSLTResponseWriter
   [junit4]   2> 10264 T29 oasr.XSLTResponseWriter.init xsltCacheLifetimeSeconds=5
   [junit4]   2> 11353 T29 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 11445 T29 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
   [junit4]   2> 11451 T29 oasc.RequestHandlers.initHandlersFromConfig created /query: solr.SearchHandler
   [junit4]   2> 11474 T29 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 11476 T29 oasc.RequestHandlers.initHandlersFromConfig created /browse: solr.SearchHandler
   [junit4]   2> 11509 T29 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 11529 T29 oasc.RequestHandlers.initHandlersFromConfig created /update/json: solr.JsonUpdateRequestHandler
   [junit4]   2> 11547 T29 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: solr.CSVRequestHandler
   [junit4]   2> 11549 T29 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
   [junit4]   2> 11554 T29 oasc.RequestHandlers.initHandlersFromConfig created /update/extract: solr.extraction.ExtractingRequestHandler
   [junit4]   2> 11555 T29 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.FieldAnalysisRequestHandler
   [junit4]   2> 11555 T29 oasc.RequestHandlers.initHandlersFromConfig created /analysis/field: solr.FieldAnalysisRequestHandler
   [junit4]   2> 11556 T29 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
   [junit4]   2> 11556 T29 oasc.RequestHandlers.initHandlersFromConfig created /analysis/document: solr.DocumentAnalysisRequestHandler
   [junit4]   2> 11575 T29 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
   [junit4]   2> 11595 T29 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
   [junit4]   2> 11615 T29 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
   [junit4]   2> 11663 T29 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 11664 T29 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 11664 T29 oasc.RequestHandlers.initHandlersFromConfig created /spell: solr.SearchHandler
   [junit4]   2> 11664 T29 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 11665 T29 oasc.RequestHandlers.initHandlersFromConfig created /tvrh: solr.SearchHandler
   [junit4]   2> 11665 T29 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: org.apache.solr.handler.js.JavaScriptRequestHandler
   [junit4]   2> 11665 T29 oasc.RequestHandlers.initHandlersFromConfig created /js: org.apache.solr.handler.js.JavaScriptRequestHandler
   [junit4]   2> 11665 T29 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 11666 T29 oasc.RequestHandlers.initHandlersFromConfig created /terms: solr.SearchHandler
   [junit4]   2> 11666 T29 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 11666 T29 oasc.RequestHandlers.initHandlersFromConfig created /elevate: solr.SearchHandler
   [junit4]   2> 11754 T29 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 11766 T29 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 11768 T29 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 11865 T29 oasu.CommitTracker.<init> Hard AutoCommit: if uncommited for 15000ms; 
   [junit4]   2> 11865 T29 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 11878 T29 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-3-thread-1]: init: current segments file is "segments_1"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@6c91f037
   [junit4]   2> 11879 T29 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-3-thread-1]: init: load commit "segments_1"
   [junit4]   2> 11879 T29 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@60590c33 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e67797a),segFN=segments_1,generation=1}
   [junit4]   2> 11879 T29 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 11880 T29 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-3-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 11880 T29 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-3-thread-1]: 0 msec to checkpoint
   [junit4]   2> 11880 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: init: create=false
   [junit4]   2> 11880 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: 
   [junit4]   2> 	dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@60590c33 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e67797a)
   [junit4]   2> 	index=
   [junit4]   2> 	version=5.0-SNAPSHOT
   [junit4]   2> 	matchVersion=LUCENE_50
   [junit4]   2> 	analyzer=null
   [junit4]   2> 	ramBufferSizeMB=100.0
   [junit4]   2> 	maxBufferedDocs=-1
   [junit4]   2> 	maxBufferedDeleteTerms=-1
   [junit4]   2> 	mergedSegmentWarmer=null
   [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=Lucene45
   [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@571f152c
   [junit4]   2> 	readerPooling=false
   [junit4]   2> 	perThreadHardLimitMB=1945
   [junit4]   2> 	useCompoundFile=false
   [junit4]   2> 	
   [junit4]   2> 11891 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: flush at getReader
   [junit4]   2> 11891 T29 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-3-thread-1]: coreLoadExecutor-3-thread-1 startFullFlush
   [junit4]   2> 11891 T29 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-3-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 11892 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: apply all deletes during flush
   [junit4]   2> 11892 T29 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-3-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@34fd6741 minGen=9223372036854775807 packetCount=0
   [junit4]   2> 11901 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
   [junit4]   2> 11901 T29 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-3-thread-1]: coreLoadExecutor-3-thread-1 finishFullFlush success=true
   [junit4]   2> 11901 T29 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: getReader took 10 msec
   [junit4]   2> 11929 T29 oass.SolrIndexSearcher.<init> Opening Searcher@12cd0108 main
   [junit4]   2> 11970 T29 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 12037 T29 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> 12100 T29 oashc.SpellCheckComponent.inform No queryConverter defined, using default converter
   [junit4]   2> 12117 T29 oashc.QueryElevationComponent.inform Loading QueryElevation from: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\conf\elevate.xml
   [junit4]   2> 12405 T29 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 12427 T30 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@12cd0108 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> ASYNC  NEW_CORE C0 name=collection1 org.apache.solr.core.SolrCore@41b8d543
   [junit4]   2> 12784 T30 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={event=firstSearcher&q=static+firstSearcher+warming+in+solrconfig.xml&distrib=false} hits=0 status=0 QTime=341 
   [junit4]   2> 12792 T30 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 12793 T30 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
   [junit4]   2> 12793 T30 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
   [junit4]   2> 12797 T30 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@12cd0108 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 12809 T29 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 12817 T17 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0
   [junit4]   2> 12818 T17 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 12818 T17 oas.SolrJettyTestBase.createJetty Jetty Assigned Port#52890
   [junit4]   2> 12835 T17 oas.SolrTestCaseJ4.setUp ###Starting testLukeHandler
   [junit4]   2> 12873 T17 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> ASYNC  NEW_CORE C1 name=collection1 org.apache.solr.core.SolrCore@41b8d543
   [junit4]   2> 14111 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 14114 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
   [junit4]   2> 14115 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 14119 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: flush at getReader
   [junit4]   2> 14124 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: qtp1995335269-23 startFullFlush
   [junit4]   2> 14124 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 14131 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: qtp1995335269-23: flush naked frozen global deletes
   [junit4]   2> 14159 T23 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-23]: push deletes  1 deleted queries bytesUsed=32 delGen=2 packetCount=1 totBytesUsed=32
   [junit4]   2> 14170 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: flush: push buffered deletes:  1 deleted queries bytesUsed=32
   [junit4]   2> 14170 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: apply all deletes during flush
   [junit4]   2> 14170 T23 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-23]: prune sis=org.apache.lucene.index.SegmentInfos@34fd6741 minGen=9223372036854775807 packetCount=1
   [junit4]   2> 14171 T23 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-23]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 14171 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
   [junit4]   2> 14171 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: qtp1995335269-23 finishFullFlush success=true
   [junit4]   2> 14172 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: getReader took 53 msec
   [junit4]   2> 14181 T23 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1445827646256578560)} 0 203
   [junit4]   2> 14543 T25 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[ID0 (1445827646531305472)]} 0 264
   [junit4]   2> 14554 T26 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[ID1 (1445827646815469568)]} 0 1
   [junit4]   2> 14569 T27 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[ID2 (1445827646829101056)]} 0 4
   [junit4]   2> 14581 T28 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[ID3 (1445827646844829696)]} 0 1
   [junit4]   2> 14594 T24 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[ID4 (1445827646856364032)]} 0 3
   [junit4]   2> 14780 T23 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 14781 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: commit: start
   [junit4]   2> 14781 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: commit: enter lock
   [junit4]   2> 14781 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: commit: now prepare
   [junit4]   2> 14781 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: prepareCommit: flush
   [junit4]   2> 14782 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]:   index before flush 
   [junit4]   2> 14783 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: qtp1995335269-23 startFullFlush
   [junit4]   2> 14783 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: anyChanges? numDocsInRam=5 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 14785 T23 C1 oasu.LoggingInfoStream.message [DWFC][qtp1995335269-23]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 4 deleted terms (unique count=4) bytesUsed=668, segment=_0, aborting=false, numDocsInRAM=5, deleteQueue=DWDQ: [ generation: 2 ]]
   [junit4]   2> 14802 T23 C1 oasu.LoggingInfoStream.message [DWPT][qtp1995335269-23]: flush postings as segment _0 numDocs=5
   [junit4]   2> 14973 T23 C1 oasu.LoggingInfoStream.message [DWPT][qtp1995335269-23]: new segment has 0 deleted docs
   [junit4]   2> 14974 T23 C1 oasu.LoggingInfoStream.message [DWPT][qtp1995335269-23]: new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   2> 14976 T23 C1 oasu.LoggingInfoStream.message [DWPT][qtp1995335269-23]: flushedFiles=[_0.fnm, _0_Lucene41_0.doc, _0.fdx, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0.fdt]
   [junit4]   2> 14976 T23 C1 oasu.LoggingInfoStream.message [DWPT][qtp1995335269-23]: flushed codec=Lucene45
   [junit4]   2> 14980 T23 C1 oasu.LoggingInfoStream.message [DWPT][qtp1995335269-23]: flushed: segment=_0 ramUsed=0.063 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=7,394.753
   [junit4]   2> 14998 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: publishFlushedSegment seg-private deletes=null
   [junit4]   2> 14999 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: publishFlushedSegment
   [junit4]   2> 14999 T23 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-23]: push deletes  5 deleted terms (unique count=5) bytesUsed=1024 delGen=4 packetCount=1 totBytesUsed=1024
   [junit4]   2> 15000 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: publish sets newSegment delGen=5 seg=_0(5.0):C5
   [junit4]   2> 15000 T23 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-23]: now checkpoint "_0(5.0):C5" [1 segments ; isCommit = false]
   [junit4]   2> 15002 T23 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-23]: 1 msec to checkpoint
   [junit4]   2> 15003 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: apply all deletes during flush
   [junit4]   2> 15006 T23 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-23]: applyDeletes: infos=[_0(5.0):C5] packetCount=1
   [junit4]   2> 15007 T23 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-23]: applyDeletes took 1 msec
   [junit4]   2> 15008 T23 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-23]: prune sis=org.apache.lucene.index.SegmentInfos@34fd6741 minGen=6 packetCount=1
   [junit4]   2> 15009 T23 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-23]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 15009 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: qtp1995335269-23 finishFullFlush success=true
   [junit4]   2> 15015 T23 C1 oasu.LoggingInfoStream.message [TMP][qtp1995335269-23]: findMerges: 1 segments
   [junit4]   2> 15028 T23 C1 oasu.LoggingInfoStream.message [TMP][qtp1995335269-23]:   seg=_0(5.0):C5 size=0.000 MB [floored]
   [junit4]   2> 15030 T23 C1 oasu.LoggingInfoStream.message [TMP][qtp1995335269-23]:   allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
   [junit4]   2> 15030 T23 C1 oasu.LoggingInfoStream.message [CMS][qtp1995335269-23]: now merge
   [junit4]   2> 15031 T23 C1 oasu.LoggingInfoStream.message [CMS][qtp1995335269-23]:   index: _0(5.0):C5
   [junit4]   2> 15031 T23 C1 oasu.LoggingInfoStream.message [CMS][qtp1995335269-23]:   no more merges pending; now return
   [junit4]   2> 15031 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: startCommit(): start
   [junit4]   2> 15031 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: startCommit index=_0(5.0):C5 changeCount=3
   [junit4]   2> 15032 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: done all syncs: [_0.fnm, _0_Lucene41_0.doc, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip]
   [junit4]   2> 15032 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: commit: pendingCommit != null
   [junit4]   2> 15039 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: commit: wrote segments file "segments_2"
   [junit4]   2> 15040 T23 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-23]: now checkpoint "_0(5.0):C5" [1 segments ; isCommit = true]
   [junit4]   2> 15040 T23 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@60590c33 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e67797a),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@60590c33 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e67797a),segFN=segments_2,generation=2}
   [junit4]   2> 15042 T23 C1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 15042 T23 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-23]: deleteCommits: now decRef commit "segments_1"
   [junit4]   2> 15043 T23 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-23]: delete "segments_1"
   [junit4]   2> 15044 T23 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-23]: 4 msec to checkpoint
   [junit4]   2> 15045 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: commit: done
   [junit4]   2> 15046 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 15047 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
   [junit4]   2> 15047 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: flush at getReader
   [junit4]   2> 15047 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: qtp1995335269-23 startFullFlush
   [junit4]   2> 15047 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 15049 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: apply all deletes during flush
   [junit4]   2> 15050 T23 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-23]: applyDeletes: no deletes; skipping
   [junit4]   2> 15050 T23 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-23]: prune sis=org.apache.lucene.index.SegmentInfos@34fd6741 minGen=6 packetCount=0
   [junit4]   2> 15192 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: return reader version=3 reader=StandardDirectoryReader(segments_2:3:nrt _0(5.0):C5)
   [junit4]   2> 15193 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: qtp1995335269-23 finishFullFlush success=true
   [junit4]   2> 15193 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: getReader took 146 msec
   [junit4]   2> 15194 T23 C1 oass.SolrIndexSearcher.<init> Opening Searcher@33bca541 main
   [junit4]   2> 15217 T23 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 15218 T30 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@33bca541 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C5)}
   [junit4]   2> 15220 T30 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 15247 T30 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@33bca541 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C5)}
   [junit4]   2> 15250 T23 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 470
   [junit4]   2> 15373 T27 C1 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=5 status=0 QTime=86 
   [junit4]   2> 15449 T28 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-28]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 15450 T28 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-28]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
   [junit4]   2> 15450 T28 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-28]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 15488 T28 C1 oasc.SolrCore.execute [collection1] webapp=/solr path=/admin/luke params={wt=javabin&version=2} status=0 QTime=45 
   [junit4]   2> 15523 T25 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-25]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 15524 T25 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-25]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
   [junit4]   2> 15524 T25 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-25]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 15532 T25 C1 oasc.SolrCore.execute [collection1] webapp=/solr path=/admin/luke params={show=schema&wt=javabin&version=2} status=0 QTime=10 
   [junit4]   2> 15606 T17 oas.SolrTestCaseJ4.tearDown ###Ending testLukeHandler
   [junit4]   2> 15644 T17 oas.SolrTestCaseJ4.setUp ###Starting testPingHandler
   [junit4]   2> 15661 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 15663 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
   [junit4]   2> 15663 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 15670 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: flush at getReader
   [junit4]   2> 15670 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: qtp1995335269-26 startFullFlush
   [junit4]   2> 15671 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 15671 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: qtp1995335269-26: flush naked frozen global deletes
   [junit4]   2> 15672 T26 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-26]: push deletes  1 deleted queries bytesUsed=32 delGen=8 packetCount=1 totBytesUsed=32
   [junit4]   2> 15673 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: flush: push buffered deletes:  1 deleted queries bytesUsed=32
   [junit4]   2> 15674 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: apply all deletes during flush
   [junit4]   2> 15678 T26 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-26]: applyDeletes: infos=[_0(5.0):C5] packetCount=1
   [junit4]   2> 15921 T26 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-26]: seg=_0(5.0):C5 segGen=6 coalesced deletes=[CoalescedDeletes(termSets=1,queries=1)] newDelCount=5 100% deleted
   [junit4]   2> 15922 T26 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-26]: applyDeletes took 244 msec
   [junit4]   2> 15922 T26 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-26]: now checkpoint "_0(5.0):C5/5" [1 segments ; isCommit = false]
   [junit4]   2> 15923 T26 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-26]: 0 msec to checkpoint
   [junit4]   2> 15923 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: drop 100% deleted segments: _0(5.0):C5/5
   [junit4]   2> 15924 T26 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-26]: now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 15924 T26 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-26]: 0 msec to checkpoint
   [junit4]   2> 15924 T26 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-26]: prune sis=org.apache.lucene.index.SegmentInfos@34fd6741 minGen=9223372036854775807 packetCount=1
   [junit4]   2> 15924 T26 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-26]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 15925 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: return reader version=5 reader=StandardDirectoryReader(segments_2:5:nrt)
   [junit4]   2> 15925 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: qtp1995335269-26 finishFullFlush success=true
   [junit4]   2> 15926 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: getReader took 256 msec
   [junit4]   2> 15927 T26 C1 oass.SolrIndexSearcher.<init> Opening Searcher@6787ed60 realtime
   [junit4]   2> 15928 T26 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1445827647975194624)} 0 270
   [junit4]   2> 15955 T27 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 15955 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: commit: start
   [junit4]   2> 15956 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: commit: enter lock
   [junit4]   2> 15956 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: commit: now prepare
   [junit4]   2> 15956 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: prepareCommit: flush
   [junit4]   2> 15956 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]:   index before flush 
   [junit4]   2> 15957 T27 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-27]: qtp1995335269-27 startFullFlush
   [junit4]   2> 15957 T27 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-27]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 15957 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: apply all deletes during flush
   [junit4]   2> 15958 T27 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-27]: prune sis=org.apache.lucene.index.SegmentInfos@34fd6741 minGen=9223372036854775807 packetCount=0
   [junit4]   2> 15958 T27 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-27]: qtp1995335269-27 finishFullFlush success=true
   [junit4]   2> 15959 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: startCommit(): start
   [junit4]   2> 15959 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: startCommit index= changeCount=6
   [junit4]   2> 15960 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: done all syncs: []
   [junit4]   2> 15960 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: commit: pendingCommit != null
   [junit4]   2> 15961 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: commit: wrote segments file "segments_3"
   [junit4]   2> 15961 T27 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-27]: now checkpoint "" [0 segments ; isCommit = true]
   [junit4]   2> 15961 T27 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@60590c33 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e67797a),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@60590c33 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e67797a),segFN=segments_3,generation=3}
   [junit4]   2> 15961 T27 C1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
   [junit4]   2> 15962 T27 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-27]: deleteCommits: now decRef commit "segments_2"
   [junit4]   2> 15962 T27 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-27]: delete "_0.fnm"
   [junit4]   2> 15962 T27 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-27]: delete "_0_Lucene41_0.doc"
   [junit4]   2> 16048 T27 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-27]: unable to remove file "_0_Lucene41_0.doc": java.io.IOException: MockDirectoryWrapper: file "_0_Lucene41_0.doc" is still open: cannot delete; Will re-try later.
   [junit4]   2> 16049 T27 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-27]: delete "segments_2"
   [junit4]   2> 16049 T27 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-27]: delete "_0.fdx"
   [junit4]   2> 16049 T27 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-27]: delete "_0.si"
   [junit4]   2> 16050 T27 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-27]: delete "_0_Lucene41_0.tim"
   [junit4]   2> 16050 T27 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-27]: unable to remove file "_0_Lucene41_0.tim": java.io.IOException: MockDirectoryWrapper: file "_0_Lucene41_0.tim" is still open: cannot delete; Will re-try later.
   [junit4]   2> 16051 T27 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-27]: delete "_0.fdt"
   [junit4]   2> 16051 T27 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-27]: unable to remove file "_0.fdt": java.io.IOException: MockDirectoryWrapper: file "_0.fdt" is still open: cannot delete; Will re-try later.
   [junit4]   2> 16051 T27 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-27]: delete "_0_Lucene41_0.tip"
   [junit4]   2> 16052 T27 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-27]: 90 msec to checkpoint
   [junit4]   2> 16052 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: commit: done
   [junit4]   2> 16052 T27 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-27]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16052 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
   [junit4]   2> 16052 T27 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-27]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16054 T27 C1 oass.SolrIndexSearcher.<init> Opening Searcher@27717240 main
   [junit4]   2> 16058 T30 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@27717240 main{StandardDirectoryReader(segments_2:5:nrt)}
   [junit4]   2> 16059 T30 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 16060 T27 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 16067 T30 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@27717240 main{StandardDirectoryReader(segments_2:5:nrt)}
   [junit4]   2> 16069 T30 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete pending file _0_Lucene41_0.doc
   [junit4]   2> 16069 T30 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete "_0_Lucene41_0.doc"
   [junit4]   2> 16069 T30 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete pending file _0_Lucene41_0.tim
   [junit4]   2> 16070 T30 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete "_0_Lucene41_0.tim"
   [junit4]   2> 16070 T30 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete pending file _0.fdt
   [junit4]   2> 16070 T30 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete "_0.fdt"
   [junit4]   2> 16071 T27 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 117
   [junit4]   2> 16090 T28 C1 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=1 
   [junit4]   2> 16120 T24 C1 oasc.SolrCore.execute [collection1] webapp=/solr path=/admin/ping params={wt=javabin&version=2} hits=0 status=0 QTime=17 
   [junit4]   2> 16120 T24 C1 oasc.SolrCore.execute [collection1] webapp=/solr path=/admin/ping params={wt=javabin&version=2} status=0 QTime=18 
   [junit4]   2> 16125 T17 oas.SolrTestCaseJ4.tearDown ###Ending testPingHandler
   [junit4]   2> 16141 T17 oas.SolrTestCaseJ4.setUp ###Starting testUpdateRequestWithParameters
   [junit4]   2> 16142 T17 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 16258 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16259 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
   [junit4]   2> 16259 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16260 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: flush at getReader
   [junit4]   2> 16261 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: qtp1995335269-23 startFullFlush
   [junit4]   2> 16261 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16262 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: qtp1995335269-23: flush naked frozen global deletes
   [junit4]   2> 16262 T23 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-23]: push deletes  1 deleted queries bytesUsed=32 delGen=11 packetCount=1 totBytesUsed=32
   [junit4]   2> 16262 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: flush: push buffered deletes:  1 deleted queries bytesUsed=32
   [junit4]   2> 16263 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: apply all deletes during flush
   [junit4]   2> 16263 T23 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-23]: prune sis=org.apache.lucene.index.SegmentInfos@34fd6741 minGen=9223372036854775807 packetCount=1
   [junit4]   2> 16263 T23 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-23]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 16264 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: return reader version=5 reader=StandardDirectoryReader(segments_3:5:nrt)
   [junit4]   2> 16264 T23 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-23]: qtp1995335269-23 finishFullFlush success=true
   [junit4]   2> 16265 T23 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-23]: getReader took 5 msec
   [junit4]   2> 16266 T23 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1445827648601194496)} 0 10
   [junit4]   2> 16305 T27 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 16305 T27 C1 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 16310 T27 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-27]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16311 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
   [junit4]   2> 16311 T27 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-27]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16312 T27 C1 oass.SolrIndexSearcher.<init> Opening Searcher@161c5356 main
   [junit4]   2> 16313 T30 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@161c5356 main{StandardDirectoryReader(segments_2:5:nrt)}
   [junit4]   2> 16314 T30 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 16314 T27 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 16319 T30 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@161c5356 main{StandardDirectoryReader(segments_2:5:nrt)}
   [junit4]   2> 16321 T27 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 17
   [junit4]   2> 16336 T28 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={overwrite=false&wt=javabin&version=2} {add=[id1 (1445827648681934848)]} 0 3
   [junit4]   2> 16346 T25 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={overwrite=false&wt=javabin&version=2} {add=[id1 (1445827648693469184)]} 0 2
   [junit4]   2> 16351 T26 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 16351 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: commit: start
   [junit4]   2> 16351 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: commit: enter lock
   [junit4]   2> 16351 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: commit: now prepare
   [junit4]   2> 16351 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: prepareCommit: flush
   [junit4]   2> 16351 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]:   index before flush 
   [junit4]   2> 16352 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: qtp1995335269-26 startFullFlush
   [junit4]   2> 16352 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: anyChanges? numDocsInRam=2 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16353 T26 C1 oasu.LoggingInfoStream.message [DWFC][qtp1995335269-26]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_1, aborting=false, numDocsInRAM=2, deleteQueue=DWDQ: [ generation: 7 ]]
   [junit4]   2> 16353 T26 C1 oasu.LoggingInfoStream.message [DWPT][qtp1995335269-26]: flush postings as segment _1 numDocs=2
   [junit4]   2> 16355 T26 C1 oasu.LoggingInfoStream.message [DWPT][qtp1995335269-26]: new segment has 0 deleted docs
   [junit4]   2> 16356 T26 C1 oasu.LoggingInfoStream.message [DWPT][qtp1995335269-26]: new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   2> 16356 T26 C1 oasu.LoggingInfoStream.message [DWPT][qtp1995335269-26]: flushedFiles=[_1.fdx, _1_Lucene41_0.doc, _1.fdt, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _1.fnm]
   [junit4]   2> 16356 T26 C1 oasu.LoggingInfoStream.message [DWPT][qtp1995335269-26]: flushed codec=Lucene45
   [junit4]   2> 16357 T26 C1 oasu.LoggingInfoStream.message [DWPT][qtp1995335269-26]: flushed: segment=_1 ramUsed=0.063 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=3,466.367
   [junit4]   2> 16357 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: publishFlushedSegment seg-private deletes=null
   [junit4]   2> 16357 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: publishFlushedSegment
   [junit4]   2> 16358 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: publish sets newSegment delGen=13 seg=_1(5.0):C2
   [junit4]   2> 16358 T26 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-26]: now checkpoint "_1(5.0):C2" [1 segments ; isCommit = false]
   [junit4]   2> 16358 T26 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-26]: 0 msec to checkpoint
   [junit4]   2> 16366 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: apply all deletes during flush
   [junit4]   2> 16367 T26 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-26]: applyDeletes: no deletes; skipping
   [junit4]   2> 16372 T26 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-26]: prune sis=org.apache.lucene.index.SegmentInfos@34fd6741 minGen=13 packetCount=0
   [junit4]   2> 16373 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: qtp1995335269-26 finishFullFlush success=true
   [junit4]   2> 16374 T26 C1 oasu.LoggingInfoStream.message [TMP][qtp1995335269-26]: findMerges: 1 segments
   [junit4]   2> 16375 T26 C1 oasu.LoggingInfoStream.message [TMP][qtp1995335269-26]:   seg=_1(5.0):C2 size=0.000 MB [floored]
   [junit4]   2> 16375 T26 C1 oasu.LoggingInfoStream.message [TMP][qtp1995335269-26]:   allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
   [junit4]   2> 16376 T26 C1 oasu.LoggingInfoStream.message [CMS][qtp1995335269-26]: now merge
   [junit4]   2> 16376 T26 C1 oasu.LoggingInfoStream.message [CMS][qtp1995335269-26]:   index: _1(5.0):C2
   [junit4]   2> 16376 T26 C1 oasu.LoggingInfoStream.message [CMS][qtp1995335269-26]:   no more merges pending; now return
   [junit4]   2> 16376 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: startCommit(): start
   [junit4]   2> 16376 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: startCommit index=_1(5.0):C2 changeCount=9
   [junit4]   2> 16377 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: done all syncs: [_1.fdx, _1_Lucene41_0.doc, _1.fdt, _1.si, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _1.fnm]
   [junit4]   2> 16378 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: commit: pendingCommit != null
   [junit4]   2> 16378 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: commit: wrote segments file "segments_4"
   [junit4]   2> 16378 T26 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-26]: now checkpoint "_1(5.0):C2" [1 segments ; isCommit = true]
   [junit4]   2> 16379 T26 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@60590c33 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e67797a),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@60590c33 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e67797a),segFN=segments_4,generation=4}
   [junit4]   2> 16380 T26 C1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
   [junit4]   2> 16380 T26 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-26]: deleteCommits: now decRef commit "segments_3"
   [junit4]   2> 16381 T26 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-26]: delete "segments_3"
   [junit4]   2> 16381 T26 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-26]: 2 msec to checkpoint
   [junit4]   2> 16381 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: commit: done
   [junit4]   2> 16382 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16382 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
   [junit4]   2> 16382 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: flush at getReader
   [junit4]   2> 16382 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: qtp1995335269-26 startFullFlush
   [junit4]   2> 16383 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16383 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: apply all deletes during flush
   [junit4]   2> 16385 T26 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-26]: applyDeletes: no deletes; skipping
   [junit4]   2> 16385 T26 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-26]: prune sis=org.apache.lucene.index.SegmentInfos@34fd6741 minGen=13 packetCount=0
   [junit4]   2> 16389 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: return reader version=7 reader=StandardDirectoryReader(segments_4:7:nrt _1(5.0):C2)
   [junit4]   2> 16390 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: qtp1995335269-26 finishFullFlush success=true
   [junit4]   2> 16391 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: getReader took 9 msec
   [junit4]   2> 16391 T26 C1 oass.SolrIndexSearcher.<init> Opening Searcher@4cf5354c main
   [junit4]   2> 16392 T26 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 16392 T30 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@4cf5354c main{StandardDirectoryReader(segments_4:7:nrt _1(5.0):C2)}
   [junit4]   2> 16393 T30 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 16398 T30 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4cf5354c main{StandardDirectoryReader(segments_4:7:nrt _1(5.0):C2)}
   [junit4]   2> 16408 T26 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 58
   [junit4]   2> 16419 T23 C1 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=2 status=0 QTime=1 
   [junit4]   2> 16423 T17 oas.SolrTestCaseJ4.tearDown ###Ending testUpdateRequestWithParameters
   [junit4]   2> 16444 T17 oas.SolrTestCaseJ4.setUp ###Starting testGetEmptyResults
   [junit4]   2> 16450 T27 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-27]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16450 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
   [junit4]   2> 16451 T27 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-27]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16451 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: flush at getReader
   [junit4]   2> 16451 T27 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-27]: qtp1995335269-27 startFullFlush
   [junit4]   2> 16452 T27 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-27]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16453 T27 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-27]: qtp1995335269-27: flush naked frozen global deletes
   [junit4]   2> 16453 T27 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-27]: push deletes  1 deleted queries bytesUsed=32 delGen=16 packetCount=1 totBytesUsed=32
   [junit4]   2> 16453 T27 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-27]: flush: push buffered deletes:  1 deleted queries bytesUsed=32
   [junit4]   2> 16453 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: apply all deletes during flush
   [junit4]   2> 16454 T27 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-27]: applyDeletes: infos=[_1(5.0):C2] packetCount=1
   [junit4]   2> 16457 T27 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-27]: seg=_1(5.0):C2 segGen=13 coalesced deletes=[CoalescedDeletes(termSets=1,queries=1)] newDelCount=2 100% deleted
   [junit4]   2> 16457 T27 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-27]: applyDeletes took 3 msec
   [junit4]   2> 16458 T27 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-27]: now checkpoint "_1(5.0):C2/2" [1 segments ; isCommit = false]
   [junit4]   2> 16458 T27 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-27]: 0 msec to checkpoint
   [junit4]   2> 16458 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: drop 100% deleted segments: _1(5.0):C2/2
   [junit4]   2> 16459 T27 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-27]: now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 16459 T27 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-27]: 0 msec to checkpoint
   [junit4]   2> 16459 T27 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-27]: prune sis=org.apache.lucene.index.SegmentInfos@34fd6741 minGen=9223372036854775807 packetCount=1
   [junit4]   2> 16459 T27 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-27]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 16460 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: return reader version=9 reader=StandardDirectoryReader(segments_4:9:nrt)
   [junit4]   2> 16460 T27 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-27]: qtp1995335269-27 finishFullFlush success=true
   [junit4]   2> 16461 T27 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-27]: getReader took 10 msec
   [junit4]   2> 16461 T27 C1 oass.SolrIndexSearcher.<init> Opening Searcher@679fe28d realtime
   [junit4]   2> 16462 T27 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1445827648803569664)} 0 13
   [junit4]   2> 16478 T28 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 16478 T28 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-28]: commit: start
   [junit4]   2> 16479 T28 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-28]: commit: enter lock
   [junit4]   2> 16479 T28 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-28]: commit: now prepare
   [junit4]   2> 16479 T28 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-28]: prepareCommit: flush
   [junit4]   2> 16479 T28 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-28]:   index before flush 
   [junit4]   2> 16480 T28 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-28]: qtp1995335269-28 startFullFlush
   [junit4]   2> 16480 T28 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-28]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16480 T28 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-28]: apply all deletes during flush
   [junit4]   2> 16481 T28 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-28]: prune sis=org.apache.lucene.index.SegmentInfos@34fd6741 minGen=9223372036854775807 packetCount=0
   [junit4]   2> 16482 T28 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-28]: qtp1995335269-28 finishFullFlush success=true
   [junit4]   2> 16482 T28 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-28]: startCommit(): start
   [junit4]   2> 16482 T28 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-28]: startCommit index= changeCount=12
   [junit4]   2> 16483 T28 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-28]: done all syncs: []
   [junit4]   2> 16483 T28 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-28]: commit: pendingCommit != null
   [junit4]   2> 16483 T28 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-28]: commit: wrote segments file "segments_5"
   [junit4]   2> 16484 T28 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-28]: now checkpoint "" [0 segments ; isCommit = true]
   [junit4]   2> 16484 T28 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@60590c33 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e67797a),segFN=segments_4,generation=4}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@60590c33 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e67797a),segFN=segments_5,generation=5}
   [junit4]   2> 16484 T28 C1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
   [junit4]   2> 16485 T28 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-28]: deleteCommits: now decRef commit "segments_4"
   [junit4]   2> 16485 T28 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-28]: delete "_1.fdx"
   [junit4]   2> 16485 T28 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-28]: delete "_1_Lucene41_0.doc"
   [junit4]   2> 16486 T28 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-28]: unable to remove file "_1_Lucene41_0.doc": java.io.IOException: MockDirectoryWrapper: file "_1_Lucene41_0.doc" is still open: cannot delete; Will re-try later.
   [junit4]   2> 16486 T28 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-28]: delete "_1.fdt"
   [junit4]   2> 16486 T28 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-28]: unable to remove file "_1.fdt": java.io.IOException: MockDirectoryWrapper: file "_1.fdt" is still open: cannot delete; Will re-try later.
   [junit4]   2> 16486 T28 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-28]: delete "_1.si"
   [junit4]   2> 16487 T28 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-28]: delete "_1_Lucene41_0.tim"
   [junit4]   2> 16487 T28 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-28]: unable to remove file "_1_Lucene41_0.tim": java.io.IOException: MockDirectoryWrapper: file "_1_Lucene41_0.tim" is still open: cannot delete; Will re-try later.
   [junit4]   2> 16487 T28 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-28]: delete "_1_Lucene41_0.tip"
   [junit4]   2> 16488 T28 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-28]: delete "_1.fnm"
   [junit4]   2> 16488 T28 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-28]: delete "segments_4"
   [junit4]   2> 16489 T28 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-28]: 5 msec to checkpoint
   [junit4]   2> 16489 T28 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-28]: commit: done
   [junit4]   2> 16489 T28 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-28]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16490 T28 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-28]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
   [junit4]   2> 16490 T28 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-28]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16492 T28 C1 oass.SolrIndexSearcher.<init> Opening Searcher@66c34f54 main
   [junit4]   2> 16494 T30 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@66c34f54 main{StandardDirectoryReader(segments_4:9:nrt)}
   [junit4]   2> 16494 T30 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 16497 T30 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@66c34f54 main{StandardDirectoryReader(segments_4:9:nrt)}
   [junit4]   2> 16526 T28 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 16527 T30 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete pending file _1_Lucene41_0.doc
   [junit4]   2> 16527 T30 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete "_1_Lucene41_0.doc"
   [junit4]   2> 16527 T30 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete pending file _1.fdt
   [junit4]   2> 16527 T30 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete "_1.fdt"
   [junit4]   2> 16527 T30 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete pending file _1_Lucene41_0.tim
   [junit4]   2> 16528 T30 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete "_1_Lucene41_0.tim"
   [junit4]   2> 16530 T28 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 52
   [junit4]   2> 16582 T24 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id1 (1445827648905281536)]} 0 37
   [junit4]   2> 16592 T25 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id2 (1445827648949321728)]} 0 4
   [junit4]   2> 16606 T26 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 16607 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: commit: start
   [junit4]   2> 16607 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: commit: enter lock
   [junit4]   2> 16608 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: commit: now prepare
   [junit4]   2> 16608 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: prepareCommit: flush
   [junit4]   2> 16608 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]:   index before flush 
   [junit4]   2> 16608 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: qtp1995335269-26 startFullFlush
   [junit4]   2> 16608 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: anyChanges? numDocsInRam=2 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16608 T26 C1 oasu.LoggingInfoStream.message [DWFC][qtp1995335269-26]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 1 deleted terms (unique count=1) bytesUsed=167, segment=_2, aborting=false, numDocsInRAM=2, deleteQueue=DWDQ: [ generation: 11 ]]
   [junit4]   2> 16609 T26 C1 oasu.LoggingInfoStream.message [DWPT][qtp1995335269-26]: flush postings as segment _2 numDocs=2
   [junit4]   2> 16645 T26 C1 oasu.LoggingInfoStream.message [DWPT][qtp1995335269-26]: new segment has 0 deleted docs
   [junit4]   2> 16645 T26 C1 oasu.LoggingInfoStream.message [DWPT][qtp1995335269-26]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 16646 T26 C1 oasu.LoggingInfoStream.message [DWPT][qtp1995335269-26]: flushedFiles=[_2_Lucene41_0.pos, _2.nvm, _2_Lucene41_0.tim, _2.nvd, _2.fdt, _2_Lucene41_0.doc, _2_Lucene41_0.tip, _2.fdx, _2.fnm]
   [junit4]   2> 16646 T26 C1 oasu.LoggingInfoStream.message [DWPT][qtp1995335269-26]: flushed codec=Lucene45
   [junit4]   2> 16646 T26 C1 oasu.LoggingInfoStream.message [DWPT][qtp1995335269-26]: flushed: segment=_2 ramUsed=0.08 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=1,336.617
   [junit4]   2> 16646 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: publishFlushedSegment seg-private deletes=null
   [junit4]   2> 16647 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: publishFlushedSegment
   [junit4]   2> 16647 T26 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-26]: push deletes  2 deleted terms (unique count=2) bytesUsed=1024 delGen=19 packetCount=1 totBytesUsed=1024
   [junit4]   2> 16647 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: publish sets newSegment delGen=20 seg=_2(5.0):C2
   [junit4]   2> 16647 T26 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-26]: now checkpoint "_2(5.0):C2" [1 segments ; isCommit = false]
   [junit4]   2> 16648 T26 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-26]: 0 msec to checkpoint
   [junit4]   2> 16648 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: apply all deletes during flush
   [junit4]   2> 16649 T26 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-26]: applyDeletes: infos=[_2(5.0):C2] packetCount=1
   [junit4]   2> 16649 T26 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-26]: applyDeletes took 1 msec
   [junit4]   2> 16649 T26 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-26]: prune sis=org.apache.lucene.index.SegmentInfos@34fd6741 minGen=21 packetCount=1
   [junit4]   2> 16650 T26 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-26]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 16650 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: qtp1995335269-26 finishFullFlush success=true
   [junit4]   2> 16650 T26 C1 oasu.LoggingInfoStream.message [TMP][qtp1995335269-26]: findMerges: 1 segments
   [junit4]   2> 16651 T26 C1 oasu.LoggingInfoStream.message [TMP][qtp1995335269-26]:   seg=_2(5.0):C2 size=0.001 MB [floored]
   [junit4]   2> 16651 T26 C1 oasu.LoggingInfoStream.message [TMP][qtp1995335269-26]:   allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
   [junit4]   2> 16651 T26 C1 oasu.LoggingInfoStream.message [CMS][qtp1995335269-26]: now merge
   [junit4]   2> 16651 T26 C1 oasu.LoggingInfoStream.message [CMS][qtp1995335269-26]:   index: _2(5.0):C2
   [junit4]   2> 16651 T26 C1 oasu.LoggingInfoStream.message [CMS][qtp1995335269-26]:   no more merges pending; now return
   [junit4]   2> 16652 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: startCommit(): start
   [junit4]   2> 16652 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: startCommit index=_2(5.0):C2 changeCount=15
   [junit4]   2> 16654 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: done all syncs: [_2.si, _2_Lucene41_0.pos, _2_Lucene41_0.tim, _2.nvm, _2.nvd, _2.fdt, _2_Lucene41_0.doc, _2_Lucene41_0.tip, _2.fdx, _2.fnm]
   [junit4]   2> 16654 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: commit: pendingCommit != null
   [junit4]   2> 16654 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: commit: wrote segments file "segments_6"
   [junit4]   2> 16655 T26 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-26]: now checkpoint "_2(5.0):C2" [1 segments ; isCommit = true]
   [junit4]   2> 16655 T26 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@60590c33 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e67797a),segFN=segments_5,generation=5}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@60590c33 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e67797a),segFN=segments_6,generation=6}
   [junit4]   2> 16655 T26 C1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
   [junit4]   2> 16656 T26 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-26]: deleteCommits: now decRef commit "segments_5"
   [junit4]   2> 16656 T26 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-26]: delete "segments_5"
   [junit4]   2> 16656 T26 C1 oasu.LoggingInfoStream.message [IFD][qtp1995335269-26]: 1 msec to checkpoint
   [junit4]   2> 16657 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: commit: done
   [junit4]   2> 16657 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16657 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
   [junit4]   2> 16657 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: flush at getReader
   [junit4]   2> 16657 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: qtp1995335269-26 startFullFlush
   [junit4]   2> 16658 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 16658 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: apply all deletes during flush
   [junit4]   2> 16659 T26 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-26]: applyDeletes: no deletes; skipping
   [junit4]   2> 16659 T26 C1 oasu.LoggingInfoStream.message [BD][qtp1995335269-26]: prune sis=org.apache.lucene.index.SegmentInfos@34fd6741 minGen=21 packetCount=0
   [junit4]   2> 16704 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: return reader version=11 reader=StandardDirectoryReader(segments_6:11:nrt _2(5.0):C2)
   [junit4]   2> 16704 T26 C1 oasu.LoggingInfoStream.message [DW][qtp1995335269-26]: qtp1995335269-26 finishFullFlush success=true
   [junit4]   2> 16704 T26 C1 oasu.LoggingInfoStream.message [IW][qtp1995335269-26]: getReader took 47 msec
   [junit4]   2> 16704 T26 C1 oass.SolrIndexSearcher.<init> Opening Searcher@2d9d62fe main
   [junit4]   2> 16706 T30 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@2d9d62fe main{StandardDirectoryReader(segments_6:11:nrt _2(5.0):C2)}
   [junit4]   2> 16706 T30 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 16706 T26 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 16708 T30 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2d9d62fe main{StandardDirectoryReader(segments_6:11:nrt _2(5.0):C2)}
   [junit4]   2> 16709 T26 C1 oasup.LogUp

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

ttp client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 226137 T26 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/info/system params={wt=javabin&qt=/admin/info/system&version=2} status=0 QTime=9 
   [junit4]   2> 226143 T17 oas.SolrTestCaseJ4.tearDown ###Ending testExampleConfig
   [junit4]   2> 226160 T17 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1314241569
   [junit4]   2> 226161 T17 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@41b8d543
   [junit4]   2> 226179 T17 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=55,autocommit maxTime=15000ms,autocommits=1,soft autocommits=3,optimizes=2,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=1,cumulative_adds=118,cumulative_deletesById=5,cumulative_deletesByQuery=25,cumulative_errors=1}
   [junit4]   2> 226181 T17 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 226181 T17 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 226181 T17 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 226190 T17 C5 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: now flush at close waitForMerges=true
   [junit4]   2> 226190 T17 C5 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]:   start flush: applyAllDeletes=true
   [junit4]   2> 226192 T17 C5 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]:   index before flush _11(5.0):C5
   [junit4]   2> 226192 T17 C5 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker startFullFlush
   [junit4]   2> 226192 T17 C5 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 226192 T17 C5 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker finishFullFlush success=true
   [junit4]   2> 226192 T17 C5 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: apply all deletes during flush
   [junit4]   2> 226193 T17 C5 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: applyDeletes: no deletes; skipping
   [junit4]   2> 226193 T17 C5 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@34fd6741 minGen=212 packetCount=0
   [junit4]   2> 226193 T17 C5 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: now merge
   [junit4]   2> 226193 T17 C5 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]:   index: _11(5.0):C5
   [junit4]   2> 226193 T17 C5 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]:   no more merges pending; now return
   [junit4]   2> 226194 T17 C5 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: waitForMerges
   [junit4]   2> 226194 T17 C5 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: waitForMerges done
   [junit4]   2> 226194 T17 C5 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: now call final commit()
   [junit4]   2> 226194 T17 C5 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: commit: start
   [junit4]   2> 226194 T17 C5 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: commit: enter lock
   [junit4]   2> 226195 T17 C5 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: commit: now prepare
   [junit4]   2> 226195 T17 C5 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: prepareCommit: flush
   [junit4]   2> 226195 T17 C5 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]:   index before flush _11(5.0):C5
   [junit4]   2> 226196 T17 C5 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker startFullFlush
   [junit4]   2> 226196 T17 C5 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 226196 T17 C5 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: apply all deletes during flush
   [junit4]   2> 226198 T17 C5 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: applyDeletes: no deletes; skipping
   [junit4]   2> 226198 T17 C5 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@34fd6741 minGen=212 packetCount=0
   [junit4]   2> 226198 T17 C5 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker finishFullFlush success=true
   [junit4]   2> 226199 T17 C5 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: startCommit(): start
   [junit4]   2> 226199 T17 C5 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]:   skip startCommit(): no changes pending
   [junit4]   2> 226199 T17 C5 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: commit: pendingCommit == null; skip
   [junit4]   2> 226199 T17 C5 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: commit: done
   [junit4]   2> 226199 T17 C5 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[6C5A4F226687798E]-worker]: at close: _11(5.0):C5
   [junit4]   2> 226205 T17 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 226205 T17 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 226207 T17 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleBinaryTest-1378848681449\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleBinaryTest-1378848681449\;done=false>>]
   [junit4]   2> 226208 T17 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleBinaryTest-1378848681449\
   [junit4]   2> 226208 T17 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleBinaryTest-1378848681449\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleBinaryTest-1378848681449\index;done=false>>]
   [junit4]   2> 226208 T17 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleBinaryTest-1378848681449\index
   [junit4]   2> 226209 T17 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 226265 T17 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=fr_CH, timezone=JST
   [junit4]   2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.8.0-ea (64-bit)/cpus=2,threads=1,free=59901992,total=95944704
   [junit4]   2> NOTE: All tests run in this JVM: [ContentStreamTest, TestUpdateRequestCodec, SolrQueryTest, SolrExampleBinaryTest]
   [junit4] Completed in 223.92s, 26 tests, 1 error <<< FAILURES!

[...truncated 137 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:396: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:376: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:202: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:455: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1230: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:873: There were test failures: 46 suites, 272 tests, 1 error, 1 ignored (1 assumption)

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



Mime
View raw message