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-Linux (32bit/jdk1.8.0-ea-b102) - Build # 7372 - Still Failing!
Date Sun, 08 Sep 2013 11:06:55 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/7372/
Java: 32bit/jdk1.8.0-ea-b102 -server -XX:+UseConcMarkSweepGC

1 tests failed.
FAILED:  org.apache.solr.client.solrj.embedded.SolrExampleJettyTest.testChineseDefaults

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

Stack Trace:
org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:32992/solr/collection1
	at __randomizedtesting.SeedInfo.seed([6EEA9062DF94C2A1:D4A98E25AC12477B]: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.testChineseDefaults(SolrExampleTests.java:1280)
	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 10889 lines...]
   [junit4] Suite: org.apache.solr.client.solrj.embedded.SolrExampleJettyTest
   [junit4]   2> 34113 T70 oas.SolrJettyTestBase.beforeSolrJettyTestBase Randomized ssl (true) and clientAuth (false)
   [junit4]   2> 34114 T70 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/./solrtest-SolrExampleJettyTest-1378638202911
   [junit4]   2> 34114 T70 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 34120 T70 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 34310 T70 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 34314 T70 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:32992
   [junit4]   2> 34315 T70 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 34315 T70 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 34315 T70 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr
   [junit4]   2> 34316 T70 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/'
   [junit4]   2> 34333 T70 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/solr.xml
   [junit4]   2> 34382 T70 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 34383 T70 oasc.CoreContainer.<init> New CoreContainer 20669492
   [junit4]   2> 34383 T70 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/]
   [junit4]   2> 34384 T70 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 34384 T70 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 34384 T70 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 34384 T70 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 34385 T70 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 34385 T70 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 34385 T70 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 34385 T70 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 34386 T70 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 34386 T70 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
   [junit4]   2> 34388 T70 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 34389 T70 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 34390 T70 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr
   [junit4]   2> 34391 T70 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/
   [junit4]   2> 34394 T70 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 34401 T80 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1
   [junit4]   2> 34402 T80 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/'
   [junit4]   2> 34436 T80 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
   [junit4]   2> 34436 T80 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/extraction/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../contrib/extraction/lib).
   [junit4]   2> 34437 T80 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../dist).
   [junit4]   2> 34437 T80 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/clustering/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../contrib/clustering/lib).
   [junit4]   2> 34437 T80 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../dist).
   [junit4]   2> 34438 T80 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/langid/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../contrib/langid/lib).
   [junit4]   2> 34438 T80 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../dist).
   [junit4]   2> 34438 T80 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/velocity/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../contrib/velocity/lib).
   [junit4]   2> 34438 T80 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../dist).
   [junit4]   2> 34464 T80 oasu.SolrIndexConfig.<init> IndexWriter infoStream solr logging is enabled
   [junit4]   2> 34466 T80 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 34531 T80 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 34532 T80 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 34549 T80 oass.IndexSchema.readSchema [null] Schema name=example
   [junit4]   2> 34832 T80 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 34846 T80 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 34850 T80 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 34877 T80 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 34878 T80 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911/
   [junit4]   2> 34878 T80 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@15f13d6
   [junit4]   2> 34879 T80 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
   [junit4]   2> 34879 T80 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
   [junit4]   2> 34888 T80 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911
   [junit4]   2> 34888 T80 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911/index/
   [junit4]   2> 34889 T80 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911/index' doesn't exist. Creating new index...
   [junit4]   2> 34889 T80 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911/index
   [junit4]   2> 34890 T80 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-18-thread-1]: init: current segments file is "null"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@16174d7
   [junit4]   2> 34890 T80 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-18-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 34890 T80 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-18-thread-1]: 0 msec to checkpoint
   [junit4]   2> 34891 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: init: create=true
   [junit4]   2> 34891 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: 
   [junit4]   2> 	dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3)
   [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@4ef334
   [junit4]   2> 	readerPooling=false
   [junit4]   2> 	perThreadHardLimitMB=1945
   [junit4]   2> 	useCompoundFile=false
   [junit4]   2> 	
   [junit4]   2> 34891 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: now flush at close waitForMerges=true
   [junit4]   2> 34892 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]:   start flush: applyAllDeletes=true
   [junit4]   2> 34892 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]:   index before flush 
   [junit4]   2> 34892 T80 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-18-thread-1]: coreLoadExecutor-18-thread-1 startFullFlush
   [junit4]   2> 34892 T80 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-18-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 34892 T80 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-18-thread-1]: coreLoadExecutor-18-thread-1 finishFullFlush success=true
   [junit4]   2> 34893 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: apply all deletes during flush
   [junit4]   2> 34893 T80 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-18-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@7620fc minGen=9223372036854775807 packetCount=0
   [junit4]   2> 34893 T80 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-18-thread-1]: now merge
   [junit4]   2> 34893 T80 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-18-thread-1]:   index: 
   [junit4]   2> 34894 T80 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-18-thread-1]:   no more merges pending; now return
   [junit4]   2> 34894 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: waitForMerges
   [junit4]   2> 34894 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: waitForMerges done
   [junit4]   2> 34894 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: now call final commit()
   [junit4]   2> 34894 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: commit: start
   [junit4]   2> 34895 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: commit: enter lock
   [junit4]   2> 34895 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: commit: now prepare
   [junit4]   2> 34895 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: prepareCommit: flush
   [junit4]   2> 34895 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]:   index before flush 
   [junit4]   2> 34895 T80 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-18-thread-1]: coreLoadExecutor-18-thread-1 startFullFlush
   [junit4]   2> 34896 T80 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-18-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 34896 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: apply all deletes during flush
   [junit4]   2> 34896 T80 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-18-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@7620fc minGen=9223372036854775807 packetCount=0
   [junit4]   2> 34896 T80 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-18-thread-1]: coreLoadExecutor-18-thread-1 finishFullFlush success=true
   [junit4]   2> 34897 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: startCommit(): start
   [junit4]   2> 34897 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: startCommit index= changeCount=1
   [junit4]   2> 34897 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: done all syncs: []
   [junit4]   2> 34897 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: commit: pendingCommit != null
   [junit4]   2> 34898 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: commit: wrote segments file "segments_1"
   [junit4]   2> 34898 T80 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-18-thread-1]: now checkpoint "" [0 segments ; isCommit = true]
   [junit4]   2> 34898 T80 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_1,generation=1}
   [junit4]   2> 34898 T80 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 34899 T80 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-18-thread-1]: 0 msec to checkpoint
   [junit4]   2> 34899 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: commit: done
   [junit4]   2> 34899 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: at close: 
   [junit4]   2> 34900 T80 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
   [junit4]   2> 34900 T80 oasc.SolrCore.initWriters adding lazy queryResponseWriter: solr.VelocityResponseWriter
   [junit4]   2> 34900 T80 oasc.SolrCore.initWriters created velocity: solr.VelocityResponseWriter
   [junit4]   2> 34900 T80 oasc.SolrCore.initWriters created xslt: solr.XSLTResponseWriter
   [junit4]   2> 34900 T80 oasr.XSLTResponseWriter.init xsltCacheLifetimeSeconds=5
   [junit4]   2> 34903 T80 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 34904 T80 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
   [junit4]   2> 34904 T80 oasc.RequestHandlers.initHandlersFromConfig created /query: solr.SearchHandler
   [junit4]   2> 34905 T80 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 34905 T80 oasc.RequestHandlers.initHandlersFromConfig created /browse: solr.SearchHandler
   [junit4]   2> 34905 T80 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 34906 T80 oasc.RequestHandlers.initHandlersFromConfig created /update/json: solr.JsonUpdateRequestHandler
   [junit4]   2> 34906 T80 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: solr.CSVRequestHandler
   [junit4]   2> 34906 T80 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
   [junit4]   2> 34907 T80 oasc.RequestHandlers.initHandlersFromConfig created /update/extract: solr.extraction.ExtractingRequestHandler
   [junit4]   2> 34907 T80 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.FieldAnalysisRequestHandler
   [junit4]   2> 34907 T80 oasc.RequestHandlers.initHandlersFromConfig created /analysis/field: solr.FieldAnalysisRequestHandler
   [junit4]   2> 34907 T80 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
   [junit4]   2> 34908 T80 oasc.RequestHandlers.initHandlersFromConfig created /analysis/document: solr.DocumentAnalysisRequestHandler
   [junit4]   2> 34908 T80 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
   [junit4]   2> 34908 T80 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
   [junit4]   2> 34909 T80 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
   [junit4]   2> 34909 T80 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 34909 T80 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 34909 T80 oasc.RequestHandlers.initHandlersFromConfig created /spell: solr.SearchHandler
   [junit4]   2> 34909 T80 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 34910 T80 oasc.RequestHandlers.initHandlersFromConfig created /tvrh: solr.SearchHandler
   [junit4]   2> 34910 T80 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: org.apache.solr.handler.js.JavaScriptRequestHandler
   [junit4]   2> 34910 T80 oasc.RequestHandlers.initHandlersFromConfig created /js: org.apache.solr.handler.js.JavaScriptRequestHandler
   [junit4]   2> 34910 T80 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 34910 T80 oasc.RequestHandlers.initHandlersFromConfig created /terms: solr.SearchHandler
   [junit4]   2> 34910 T80 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 34911 T80 oasc.RequestHandlers.initHandlersFromConfig created /elevate: solr.SearchHandler
   [junit4]   2> 34913 T80 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 34914 T80 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 34916 T80 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 34919 T80 oasu.CommitTracker.<init> Hard AutoCommit: if uncommited for 15000ms; 
   [junit4]   2> 34919 T80 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 34920 T80 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-18-thread-1]: init: current segments file is "segments_1"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@16174d7
   [junit4]   2> 34921 T80 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-18-thread-1]: init: load commit "segments_1"
   [junit4]   2> 34921 T80 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_1,generation=1}
   [junit4]   2> 34921 T80 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 34922 T80 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-18-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 34922 T80 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-18-thread-1]: 0 msec to checkpoint
   [junit4]   2> 34922 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: init: create=false
   [junit4]   2> 34922 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: 
   [junit4]   2> 	dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3)
   [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@159892f
   [junit4]   2> 	readerPooling=false
   [junit4]   2> 	perThreadHardLimitMB=1945
   [junit4]   2> 	useCompoundFile=false
   [junit4]   2> 	
   [junit4]   2> 34923 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: flush at getReader
   [junit4]   2> 34923 T80 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-18-thread-1]: coreLoadExecutor-18-thread-1 startFullFlush
   [junit4]   2> 34923 T80 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-18-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 34924 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: apply all deletes during flush
   [junit4]   2> 34924 T80 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-18-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=9223372036854775807 packetCount=0
   [junit4]   2> 34924 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
   [junit4]   2> 34924 T80 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-18-thread-1]: coreLoadExecutor-18-thread-1 finishFullFlush success=true
   [junit4]   2> 34925 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: getReader took 2 msec
   [junit4]   2> 34925 T80 oass.SolrIndexSearcher.<init> Opening Searcher@1277f46 main
   [junit4]   2> 34925 T80 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 34926 T80 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> 34926 T80 oashc.SpellCheckComponent.inform No queryConverter defined, using default converter
   [junit4]   2> 34927 T80 oashc.QueryElevationComponent.inform Loading QueryElevation from: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/conf/elevate.xml
   [junit4]   2> 34938 T80 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 34938 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1277f46 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> ASYNC  NEW_CORE C36 name=collection1 org.apache.solr.core.SolrCore@670355
   [junit4]   2> 34941 T81 C36 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=1 
   [junit4]   2> 34941 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 34941 T81 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
   [junit4]   2> 34941 T81 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
   [junit4]   2> 34942 T81 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1277f46 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 34944 T80 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 34945 T70 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1
   [junit4]   2> 34945 T70 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 34946 T70 oas.SolrJettyTestBase.createJetty Jetty Assigned Port#32992
   [junit4]   2> 34952 T70 oas.SolrTestCaseJ4.setUp ###Starting testFaceting
   [junit4]   2> 34953 T70 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> ASYNC  NEW_CORE C37 name=collection1 org.apache.solr.core.SolrCore@670355
   [junit4]   2> 35103 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35104 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
   [junit4]   2> 35104 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35104 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: flush at getReader
   [junit4]   2> 35104 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: qtp25819770-78 startFullFlush
   [junit4]   2> 35105 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35105 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: qtp25819770-78: flush naked frozen global deletes
   [junit4]   2> 35105 T78 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-78]: push deletes  1 deleted queries bytesUsed=32 delGen=2 packetCount=1 totBytesUsed=32
   [junit4]   2> 35106 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: flush: push buffered deletes:  1 deleted queries bytesUsed=32
   [junit4]   2> 35106 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: apply all deletes during flush
   [junit4]   2> 35106 T78 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-78]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=9223372036854775807 packetCount=1
   [junit4]   2> 35106 T78 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-78]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 35107 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
   [junit4]   2> 35107 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: qtp25819770-78 finishFullFlush success=true
   [junit4]   2> 35107 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: getReader took 3 msec
   [junit4]   2> 35108 T78 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1445606933291597824)} 0 6
   [junit4]   2> 35114 T79 C37 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 35115 T79 C37 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 35115 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35116 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
   [junit4]   2> 35116 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35116 T79 C37 oass.SolrIndexSearcher.<init> Opening Searcher@19e375 main
   [junit4]   2> 35117 T79 C37 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 35117 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@19e375 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 35117 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 35118 T81 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@19e375 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 35119 T79 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 5
   [junit4]   2> 35123 T78 C37 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=1 
   [junit4]   2> 35132 T76 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1 (1445606933318860800), 2 (1445606933320957952), 3 (1445606933320957953), 4 (1445606933322006528), 5 (1445606933322006529), 6 (1445606933322006530), 7 (1445606933322006531), 8 (1445606933322006532), 9 (1445606933322006533), 10 (1445606933323055104)]} 0 5
   [junit4]   2> 35136 T79 C37 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 35136 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: start
   [junit4]   2> 35136 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: enter lock
   [junit4]   2> 35137 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: now prepare
   [junit4]   2> 35137 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: prepareCommit: flush
   [junit4]   2> 35137 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]:   index before flush 
   [junit4]   2> 35138 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 startFullFlush
   [junit4]   2> 35138 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=10 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35138 T79 C37 oasu.LoggingInfoStream.message [DWFC][qtp25819770-79]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 9 deleted terms (unique count=9) bytesUsed=1234, segment=_0, aborting=false, numDocsInRAM=10, deleteQueue=DWDQ: [ generation: 2 ]]
   [junit4]   2> 35139 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flush postings as segment _0 numDocs=10
   [junit4]   2> 35141 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: new segment has 0 deleted docs
   [junit4]   2> 35141 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 35141 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flushedFiles=[_0.fnm, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0.nvd, _0.fdx, _0.nvm, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0.fdt]
   [junit4]   2> 35142 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flushed codec=Lucene45
   [junit4]   2> 35142 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flushed: segment=_0 ramUsed=0.081 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=7,704.453
   [junit4]   2> 35143 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: publishFlushedSegment seg-private deletes=null
   [junit4]   2> 35143 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: publishFlushedSegment
   [junit4]   2> 35143 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: push deletes  10 deleted terms (unique count=10) bytesUsed=1024 delGen=4 packetCount=1 totBytesUsed=1024
   [junit4]   2> 35144 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: publish sets newSegment delGen=5 seg=_0(5.0):C10
   [junit4]   2> 35144 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: now checkpoint "_0(5.0):C10" [1 segments ; isCommit = false]
   [junit4]   2> 35144 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: 0 msec to checkpoint
   [junit4]   2> 35145 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: apply all deletes during flush
   [junit4]   2> 35145 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: applyDeletes: infos=[_0(5.0):C10] packetCount=1
   [junit4]   2> 35145 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: applyDeletes took 0 msec
   [junit4]   2> 35146 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=6 packetCount=1
   [junit4]   2> 35146 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 35146 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 finishFullFlush success=true
   [junit4]   2> 35147 T79 C37 oasu.LoggingInfoStream.message [TMP][qtp25819770-79]: findMerges: 1 segments
   [junit4]   2> 35147 T79 C37 oasu.LoggingInfoStream.message [TMP][qtp25819770-79]:   seg=_0(5.0):C10 size=0.001 MB [floored]
   [junit4]   2> 35147 T79 C37 oasu.LoggingInfoStream.message [TMP][qtp25819770-79]:   allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
   [junit4]   2> 35148 T79 C37 oasu.LoggingInfoStream.message [CMS][qtp25819770-79]: now merge
   [junit4]   2> 35148 T79 C37 oasu.LoggingInfoStream.message [CMS][qtp25819770-79]:   index: _0(5.0):C10
   [junit4]   2> 35148 T79 C37 oasu.LoggingInfoStream.message [CMS][qtp25819770-79]:   no more merges pending; now return
   [junit4]   2> 35149 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: startCommit(): start
   [junit4]   2> 35149 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: startCommit index=_0(5.0):C10 changeCount=3
   [junit4]   2> 35150 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: done all syncs: [_0.fnm, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0.nvd, _0.fdx, _0.si, _0.nvm, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip]
   [junit4]   2> 35150 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: pendingCommit != null
   [junit4]   2> 35150 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: wrote segments file "segments_2"
   [junit4]   2> 35151 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: now checkpoint "_0(5.0):C10" [1 segments ; isCommit = true]
   [junit4]   2> 35151 T79 C37 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_2,generation=2}
   [junit4]   2> 35151 T79 C37 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 35152 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: deleteCommits: now decRef commit "segments_1"
   [junit4]   2> 35152 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "segments_1"
   [junit4]   2> 35152 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: 1 msec to checkpoint
   [junit4]   2> 35152 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: done
   [junit4]   2> 35153 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35153 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
   [junit4]   2> 35153 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: flush at getReader
   [junit4]   2> 35153 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 startFullFlush
   [junit4]   2> 35154 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35154 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: apply all deletes during flush
   [junit4]   2> 35154 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: applyDeletes: no deletes; skipping
   [junit4]   2> 35154 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=6 packetCount=0
   [junit4]   2> 35155 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: return reader version=3 reader=StandardDirectoryReader(segments_2:3:nrt _0(5.0):C10)
   [junit4]   2> 35155 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 finishFullFlush success=true
   [junit4]   2> 35156 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: getReader took 3 msec
   [junit4]   2> 35156 T79 C37 oass.SolrIndexSearcher.<init> Opening Searcher@14d51e2 main
   [junit4]   2> 35156 T79 C37 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 35156 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@14d51e2 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C10)}
   [junit4]   2> 35157 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 35159 T81 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@14d51e2 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C10)}
   [junit4]   2> 35159 T79 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 23
   [junit4]   2> 35163 T77 C37 oasr.UnInvertedField.<init> UnInverted multi-valued field {field=features,memSize=4564,tindexSize=44,time=0,phase1=0,nTerms=4,bigTerms=2,termInstances=4,uses=0}
   [junit4]   2> 35164 T77 C37 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={facet=true&facet.mincount=0&q=*:*&facet.field=features&wt=javabin&version=2&rows=0} hits=10 status=0 QTime=1 
   [junit4]   2> 35168 T78 C37 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={facet=true&facet.mincount=0&q=*:*&facet.field=features&wt=javabin&fq=features:two&version=2&rows=0} hits=5 status=0 QTime=1 
   [junit4]   2> 35172 T76 C37 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={facet=true&facet.mincount=4&q=*:*&facet.field=features&wt=javabin&fq=features:two&version=2&rows=0} hits=5 status=0 QTime=1 
   [junit4]   2> 35175 T79 C37 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={facet=true&facet.mincount=-1&q=*:*&facet.field=features&wt=javabin&fq=features:two&version=2&rows=0} hits=5 status=0 QTime=1 
   [junit4]   2> 35176 T70 oas.SolrTestCaseJ4.tearDown ###Ending testFaceting
   [junit4]   2> 35182 T70 oas.SolrTestCaseJ4.setUp ###Starting testBadSetup
   [junit4]   2> 35182 T70 oas.SolrTestCaseJ4.tearDown ###Ending testBadSetup
   [junit4]   2> 35189 T70 oas.SolrTestCaseJ4.setUp ###Starting testUpdateField
   [junit4]   2> 35192 T77 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-77]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35193 T77 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-77]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
   [junit4]   2> 35193 T77 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-77]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35193 T77 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-77]: flush at getReader
   [junit4]   2> 35194 T77 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-77]: qtp25819770-77 startFullFlush
   [junit4]   2> 35194 T77 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-77]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35194 T77 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-77]: qtp25819770-77: flush naked frozen global deletes
   [junit4]   2> 35194 T77 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-77]: push deletes  1 deleted queries bytesUsed=32 delGen=8 packetCount=1 totBytesUsed=32
   [junit4]   2> 35195 T77 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-77]: flush: push buffered deletes:  1 deleted queries bytesUsed=32
   [junit4]   2> 35195 T77 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-77]: apply all deletes during flush
   [junit4]   2> 35195 T77 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-77]: applyDeletes: infos=[_0(5.0):C10] packetCount=1
   [junit4]   2> 35196 T77 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-77]: seg=_0(5.0):C10 segGen=6 coalesced deletes=[CoalescedDeletes(termSets=1,queries=1)] newDelCount=10 100% deleted
   [junit4]   2> 35196 T77 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-77]: applyDeletes took 1 msec
   [junit4]   2> 35196 T77 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-77]: now checkpoint "_0(5.0):C10/10" [1 segments ; isCommit = false]
   [junit4]   2> 35197 T77 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-77]: 0 msec to checkpoint
   [junit4]   2> 35197 T77 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-77]: drop 100% deleted segments: _0(5.0):C10/10
   [junit4]   2> 35197 T77 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-77]: now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 35197 T77 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-77]: 0 msec to checkpoint
   [junit4]   2> 35198 T77 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-77]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=9223372036854775807 packetCount=1
   [junit4]   2> 35198 T77 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-77]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 35198 T77 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-77]: return reader version=5 reader=StandardDirectoryReader(segments_2:5:nrt)
   [junit4]   2> 35198 T77 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-77]: qtp25819770-77 finishFullFlush success=true
   [junit4]   2> 35199 T77 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-77]: getReader took 6 msec
   [junit4]   2> 35199 T77 C37 oass.SolrIndexSearcher.<init> Opening Searcher@152b1 realtime
   [junit4]   2> 35199 T77 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1445606933385969664)} 0 7
   [junit4]   2> 35203 T78 C37 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 35203 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: commit: start
   [junit4]   2> 35204 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: commit: enter lock
   [junit4]   2> 35204 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: commit: now prepare
   [junit4]   2> 35204 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: prepareCommit: flush
   [junit4]   2> 35204 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]:   index before flush 
   [junit4]   2> 35205 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: qtp25819770-78 startFullFlush
   [junit4]   2> 35205 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35205 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: apply all deletes during flush
   [junit4]   2> 35205 T78 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-78]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=9223372036854775807 packetCount=0
   [junit4]   2> 35205 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: qtp25819770-78 finishFullFlush success=true
   [junit4]   2> 35206 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: startCommit(): start
   [junit4]   2> 35206 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: startCommit index= changeCount=6
   [junit4]   2> 35206 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: done all syncs: []
   [junit4]   2> 35206 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: commit: pendingCommit != null
   [junit4]   2> 35207 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: commit: wrote segments file "segments_3"
   [junit4]   2> 35207 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: now checkpoint "" [0 segments ; isCommit = true]
   [junit4]   2> 35207 T78 C37 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_3,generation=3}
   [junit4]   2> 35207 T78 C37 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
   [junit4]   2> 35208 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: deleteCommits: now decRef commit "segments_2"
   [junit4]   2> 35208 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0.fnm"
   [junit4]   2> 35208 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0_Lucene41_0.doc"
   [junit4]   2> 35208 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: 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> 35209 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0_Lucene41_0.pos"
   [junit4]   2> 35209 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: unable to remove file "_0_Lucene41_0.pos": java.io.IOException: MockDirectoryWrapper: file "_0_Lucene41_0.pos" is still open: cannot delete; Will re-try later.
   [junit4]   2> 35209 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0.nvd"
   [junit4]   2> 35209 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: unable to remove file "_0.nvd": java.io.IOException: MockDirectoryWrapper: file "_0.nvd" is still open: cannot delete; Will re-try later.
   [junit4]   2> 35210 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "segments_2"
   [junit4]   2> 35210 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0.fdx"
   [junit4]   2> 35210 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0.si"
   [junit4]   2> 35210 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0.nvm"
   [junit4]   2> 35210 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0_Lucene41_0.tim"
   [junit4]   2> 35211 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: 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> 35211 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0.fdt"
   [junit4]   2> 35211 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: unable to remove file "_0.fdt": java.io.IOException: MockDirectoryWrapper: file "_0.fdt" is still open: cannot delete; Will re-try later.
   [junit4]   2> 35211 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0_Lucene41_0.tip"
   [junit4]   2> 35212 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: 4 msec to checkpoint
   [junit4]   2> 35212 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: commit: done
   [junit4]   2> 35212 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35212 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
   [junit4]   2> 35213 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35213 T78 C37 oass.SolrIndexSearcher.<init> Opening Searcher@4270c2 main
   [junit4]   2> 35213 T78 C37 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 35213 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@4270c2 main{StandardDirectoryReader(segments_2:5:nrt)}
   [junit4]   2> 35214 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 35216 T81 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4270c2 main{StandardDirectoryReader(segments_2:5:nrt)}
   [junit4]   2> 35216 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _0_Lucene41_0.doc
   [junit4]   2> 35216 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_0_Lucene41_0.doc"
   [junit4]   2> 35216 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _0_Lucene41_0.pos
   [junit4]   2> 35217 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_0_Lucene41_0.pos"
   [junit4]   2> 35217 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _0.nvd
   [junit4]   2> 35217 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_0.nvd"
   [junit4]   2> 35217 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _0_Lucene41_0.tim
   [junit4]   2> 35217 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_0_Lucene41_0.tim"
   [junit4]   2> 35218 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _0.fdt
   [junit4]   2> 35218 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_0.fdt"
   [junit4]   2> 35218 T78 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 15
   [junit4]   2> 35222 T76 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[unique (1445606933416378368)]} 0 1
   [junit4]   2> 35225 T79 C37 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 35225 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: start
   [junit4]   2> 35226 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: enter lock
   [junit4]   2> 35226 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: now prepare
   [junit4]   2> 35226 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: prepareCommit: flush
   [junit4]   2> 35226 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]:   index before flush 
   [junit4]   2> 35226 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 startFullFlush
   [junit4]   2> 35227 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35227 T79 C37 oasu.LoggingInfoStream.message [DWFC][qtp25819770-79]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_1, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 6 ]]
   [junit4]   2> 35227 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flush postings as segment _1 numDocs=1
   [junit4]   2> 35228 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: new segment has 0 deleted docs
   [junit4]   2> 35228 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 35229 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flushedFiles=[_1.nvm, _1_Lucene41_0.pos, _1.fdx, _1_Lucene41_0.doc, _1.fdt, _1_Lucene41_0.tim, _1.nvd, _1_Lucene41_0.tip, _1.fnm]
   [junit4]   2> 35229 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flushed codec=Lucene45
   [junit4]   2> 35230 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flushed: segment=_1 ramUsed=0.079 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=942.117
   [junit4]   2> 35230 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: publishFlushedSegment seg-private deletes=null
   [junit4]   2> 35230 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: publishFlushedSegment
   [junit4]   2> 35230 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: push deletes  1 deleted terms (unique count=1) bytesUsed=1024 delGen=11 packetCount=1 totBytesUsed=1024
   [junit4]   2> 35231 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: publish sets newSegment delGen=12 seg=_1(5.0):C1
   [junit4]   2> 35231 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: now checkpoint "_1(5.0):C1" [1 segments ; isCommit = false]
   [junit4]   2> 35231 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: 0 msec to checkpoint
   [junit4]   2> 35231 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: apply all deletes during flush
   [junit4]   2> 35232 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: applyDeletes: infos=[_1(5.0):C1] packetCount=1
   [junit4]   2> 35232 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: applyDeletes took 0 msec
   [junit4]   2> 35232 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=13 packetCount=1
   [junit4]   2> 35232 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 35233 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 finishFullFlush success=true
   [junit4]   2> 35233 T79 C37 oasu.LoggingInfoStream.message [TMP][qtp25819770-79]: findMerges: 1 segments
   [junit4]   2> 35233 T79 C37 oasu.LoggingInfoStream.message [TMP][qtp25819770-79]:   seg=_1(5.0):C1 size=0.001 MB [floored]
   [junit4]   2> 35233 T79 C37 oasu.LoggingInfoStream.message [TMP][qtp25819770-79]:   allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
   [junit4]   2> 35234 T79 C37 oasu.LoggingInfoStream.message [CMS][qtp25819770-79]: now merge
   [junit4]   2> 35234 T79 C37 oasu.LoggingInfoStream.message [CMS][qtp25819770-79]:   index: _1(5.0):C1
   [junit4]   2> 35234 T79 C37 oasu.LoggingInfoStream.message [CMS][qtp25819770-79]:   no more merges pending; now return
   [junit4]   2> 35234 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: startCommit(): start
   [junit4]   2> 35234 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: startCommit index=_1(5.0):C1 changeCount=9
   [junit4]   2> 35235 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: done all syncs: [_1.fdx, _1_Lucene41_0.pos, _1.nvm, _1_Lucene41_0.doc, _1.fdt, _1.si, _1_Lucene41_0.tim, _1.nvd, _1_Lucene41_0.tip, _1.fnm]
   [junit4]   2> 35235 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: pendingCommit != null
   [junit4]   2> 35235 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: wrote segments file "segments_4"
   [junit4]   2> 35235 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: now checkpoint "_1(5.0):C1" [1 segments ; isCommit = true]
   [junit4]   2> 35236 T79 C37 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_4,generation=4}
   [junit4]   2> 35236 T79 C37 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
   [junit4]   2> 35236 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: deleteCommits: now decRef commit "segments_3"
   [junit4]   2> 35236 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "segments_3"
   [junit4]   2> 35237 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: 1 msec to checkpoint
   [junit4]   2> 35237 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: done
   [junit4]   2> 35238 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35239 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
   [junit4]   2> 35239 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: flush at getReader
   [junit4]   2> 35239 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 startFullFlush
   [junit4]   2> 35239 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35239 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: apply all deletes during flush
   [junit4]   2> 35240 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: applyDeletes: no deletes; skipping
   [junit4]   2> 35240 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=13 packetCount=0
   [junit4]   2> 35241 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: return reader version=7 reader=StandardDirectoryReader(segments_4:7:nrt _1(5.0):C1)
   [junit4]   2> 35241 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 finishFullFlush success=true
   [junit4]   2> 35241 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: getReader took 2 msec
   [junit4]   2> 35241 T79 C37 oass.SolrIndexSearcher.<init> Opening Searcher@191dec3 main
   [junit4]   2> 35242 T79 C37 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 35242 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@191dec3 main{StandardDirectoryReader(segments_4:7:nrt _1(5.0):C1)}
   [junit4]   2> 35242 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 35243 T81 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@191dec3 main{StandardDirectoryReader(segments_4:7:nrt _1(5.0):C1)}
   [junit4]   2> 35244 T79 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 19
   [junit4]   2> 35248 T77 C37 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={fl=id,price_f,name,_version_&q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=1 
   [junit4]   2> 35251 T78 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {} 0 0
   [junit4]   2> 35256 T76 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[unique (1445606933452029952)]} 0 1
   [junit4]   2> 35259 T79 C37 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 35260 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: start
   [junit4]   2> 35260 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: enter lock
   [junit4]   2> 35260 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: now prepare
   [junit4]   2> 35260 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: prepareCommit: flush
   [junit4]   2> 35261 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]:   index before flush _1(5.0):C1
   [junit4]   2> 35261 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 startFullFlush
   [junit4]   2> 35261 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35261 T79 C37 oasu.LoggingInfoStream.message [DWFC][qtp25819770-79]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_2, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 8 ]]
   [junit4]   2> 35262 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flush postings as segment _2 numDocs=1
   [junit4]   2> 35263 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: new segment has 0 deleted docs
   [junit4]   2> 35263 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 35263 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: 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> 35263 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flushed codec=Lucene45
   [junit4]   2> 35264 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flushed: segment=_2 ramUsed=0.079 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=942.117
   [junit4]   2> 35264 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: publishFlushedSegment seg-private deletes=null
   [junit4]   2> 35264 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: publishFlushedSegment
   [junit4]   2> 35265 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: push deletes  1 deleted terms (unique count=1) bytesUsed=1024 delGen=15 packetCount=1 totBytesUsed=1024
   [junit4]   2> 35265 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: publish sets newSegment delGen=16 seg=_2(5.0):C1
   [junit4]   2> 35265 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: now checkpoint "_1(5.0):C1 _2(5.0):C1" [2 segments ; isCommit = false]
   [junit4]   2> 35265 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: 0 msec to checkpoint
   [junit4]   2> 35266 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: apply all deletes during flush
   [junit4]   2> 35266 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: applyDeletes: infos=[_1(5.0):C1, _2(5.0):C1] packetCount=1
   [junit4]   2> 35266 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: seg=_1(5.0):C1 segGen=13 coalesced deletes=[CoalescedDeletes(termSets=1,queries=0)] newDelCount=1 100% deleted
   [junit4]   2> 35267 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: applyDeletes took 1 msec
   [junit4]   2> 35267 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: now checkpoint "_1(5.0):C1/1 _2(5.0):C1" [2 segments ; isCommit = false]
   [junit4]   2> 35267 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: 0 msec to checkpoint
   [junit4]   2> 35267 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: drop 100% deleted segments: _1(5.0):C1/1
   [junit4]   2> 35268 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: now checkpoint "_2(5.0):C1" [1 segments ; isCommit = false]
   [junit4]   2> 35268 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: 0 msec to checkpoint
   [junit4]   2> 35268 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=17 packetCount=1
   [junit4]   2> 35268 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 35269 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 finishFullFlush success=true
   [junit4]   2> 35269 T79 C37 oasu.LoggingInfoStream.message [TMP][qtp25819770-79]: findMerges: 1 segments
   [junit4]   2> 35269 T79 C37 oasu.LoggingInfoStream.message [TMP][qtp25819770-79]:   seg=_2(5.0):C1 size=0.001 MB [floored]
   [junit4]   2> 35269 T79 C37 oasu.LoggingInfoStream.message [TMP][qtp25819770-79]:   allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
   [junit4]   2> 35270 T79 C37 oasu.LoggingInfoStream.message [CMS][qtp25819770-79]: now merge
   [junit4]   2> 35270 T79 C37 oasu.LoggingInfoStream.message [CMS][qtp25819770-79]:   index: _2(5.0):C1
   [junit4]   2> 35270 T79 C37 oasu.LoggingInfoStream.message [CMS][qtp25819770-79]:   no more merges pending; now return
   [junit4]   2> 35270 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: startCommit(): start
   [junit4]   2> 35271 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: startCommit index=_2(5.0):C1 changeCount=14
   [junit4]   2> 35271 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: 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> 35271 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: pendingCommit != null
   [junit4]   2> 35272 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: wrote segments file "segments_5"
   [junit4]   2> 35272 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: now checkpoint "_2(5.0):C1" [1 segments ; isCommit = true]
   [junit4]   2> 35272 T79 C37 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_4,generation=4}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_5,generation=5}
   [junit4]   2> 35272 T79 C37 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
   [junit4]   2> 35273 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: deleteCommits: now decRef commit "segments_4"
   [junit4]   2> 35273 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1.fdx"
   [junit4]   2> 35273 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1_Lucene41_0.pos"
   [junit4]   2> 35273 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: unable to remove file "_1_Lucene41_0.pos": java.io.IOException: MockDirectoryWrapper: file "_1_Lucene41_0.pos" is still open: cannot delete; Will re-try later.
   [junit4]   2> 35274 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1.nvm"
   [junit4]   2> 35274 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1_Lucene41_0.doc"
   [junit4]   2> 35274 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: 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> 35274 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1.fdt"
   [junit4]   2> 35275 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: unable to remove file "_1.fdt": java.io.IOException: MockDirectoryWrapper: file "_1.fdt" is still open: cannot delete; Will re-try later.
   [junit4]   2> 35275 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1.si"
   [junit4]   2> 35275 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1_Lucene41_0.tim"
   [junit4]   2> 35276 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: 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> 35276 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1.nvd"
   [junit4]   2> 35276 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: unable to remove file "_1.nvd": java.io.IOException: MockDirectoryWrapper: file "_1.nvd" is still open: cannot delete; Will re-try later.
   [junit4]   2> 35276 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1_Lucene41_0.tip"
   [junit4]   2> 35277 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1.fnm"
   [junit4]   2> 35277 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "segments_4"
   [junit4]   2> 35277 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: 5 msec to checkpoint
   [junit4]   2> 35277 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: done
   [junit4]   2> 35278 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35278 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
   [junit4]   2> 35278 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: flush at getReader
   [junit4]   2> 35278 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 startFullFlush
   [junit4]   2> 35279 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35279 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: apply all deletes during flush
   [junit4]   2> 35279 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: applyDeletes: no deletes; skipping
   [junit4]   2> 35279 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=17 packetCount=0
   [junit4]   2> 35280 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: return reader version=11 reader=StandardDirectoryReader(segments_5:11:nrt _2(5.0):C1)
   [junit4]   2> 35280 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 finishFullFlush success=true
   [junit4]   2> 35281 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: getReader took 3 msec
   [junit4]   2> 35281 T79 C37 oass.SolrIndexSearcher.<init> Opening Searcher@1b6222 main
   [junit4]   2> 35281 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1b6222 main{StandardDirectoryReader(segments_5:11:nrt _2(5.0):C1)}
   [junit4]   2> 35282 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 35281 T79 C37 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 35290 T81 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b6222 main{StandardDirectoryReader(segments_5:11:nrt _2(5.0):C1)}
   [junit4]   2> 35291 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _1_Lucene41_0.pos
   [junit4]   2> 35291 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_1_Lucene41_0.pos"
   [junit4]   2> 35291 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _1_Lucene41_0.doc
   [junit4]   2> 35291 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_1_Lucene41_0.doc"
   [junit4]   2> 35291 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _1.fdt
   [junit4]   2> 35291 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_1.fdt"
   [junit4]   2> 35291 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _1_Lucene41_0.tim
   [junit4]   2> 35292 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_1_Lucene41_0.tim"
   [junit4]   2> 35292 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _1.nvd
   [junit4]   2> 35292 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_1.nvd"
   [junit4]   2> ASYNC  NEW_CORE C38 name=collection1 org.apache.solr.core.SolrCore@670355
   [junit4]   2> 35292 T79 C38 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 33
   [junit4]   2> 35296 T77 C38 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={fl=id,price_f,name,_version_&q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=1 
   [junit4]   2> 35300 T78 C38 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[unique (1445606933498167296)]} 0 1
   [junit4]   2> 35303 T76 C38 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 35304 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: commit: start
   [junit4]   2> 35304 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: commit: enter lock
   [junit4]   2> 35304 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: commit: now prepare
   [junit4]   2> 35304 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: prepareCommit: flush
   [junit4]   2> 35305 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]:   index before flush _2(5.0):C1
   [junit4]   2> 35305 T76 C38 oasu.LoggingInfoStream.message [DW][qtp25819770-76]: qtp25819770-76 startFullFlush
   [junit4]   2> 35305 T76 C38 oasu.LoggingInfoStream.message [DW][qtp25819770-76]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 35305 T76 C38 oasu.LoggingInfoStream.message [DWFC][qtp25819770-76]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_3, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 10 ]]
   [junit4]   2> 35306 T76 C38 oasu.LoggingInfoStream.message [DWPT][qtp25819770-76]: flush postings as segment _3 numDocs=1
   [junit4]   2> 35307 T76 C38 oasu.LoggingInfoStream.message [DWPT][qtp25819770-76]: new segment has 0 deleted docs
   [junit4]   2> 35307 T76 C38 oasu.LoggingInfoStream.message [DWPT][qtp25819770-76]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 35307 T76 C38 oasu.LoggingInfoStream.message [DWPT][qtp25819770-76]: flushedFiles=[_3.fdx, _3.nvd, _3_Lucene41_0.pos, _3_Lucene41_0.doc, _3_Lucene41_0.tip, _3.fnm, _3.nvm, _3_Lucene41_0.tim, _3.fdt]
   [junit4]   2> 35308 T76 C38 oasu.LoggingInfoStream.message [DWPT][qtp25819770-76]: flushed codec=Lucene45
   [junit4]   2> 35308 T76 C38 oasu.LoggingInfoStream.message [DWPT][qtp25819770-76]: flushed: segment=_3 ramUsed=0.079 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=942.117
   [junit4]   2> 35308 T76 C38 oasu.LoggingInfoStream.message [DW][qtp25819770-76]: publishFlushedSegment seg-private deletes=null
   [junit4]   2> 35309 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: publishFlushedSegment
   [junit4]   2> 35309 T76 C38 oasu.LoggingInfoStream.message [BD][qtp25819770-76]: push deletes  1 deleted terms (unique count=1) bytesUsed=1024 delGen=19 packetCount=1 totBytesUsed=1024
   [junit4]   2> 35309 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: publish sets newSegment delGen=20 seg=_3(5.0):C1
   [junit4]   2> 35309 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: now checkpoint "_2(5.0):C1 _3(5.0):C1" [2 segments ; isCommit = false]
   [junit4]   2> 35310 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: 0 msec to checkpoint
   [junit4]   2> 35310 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: apply all deletes during flush
   [junit4]   2> 35310 T76 C38 oasu.LoggingInfoStream.message [BD][qtp25819770-76]: applyDeletes: infos=[_2(5.0):C1, _3(5.0):C1] packetCount=1
   [junit4]   2> 35311 T76 C38 oasu.LoggingInfoStream.message [BD][qtp25819770-76]: seg=_2(5.0):C1 segGen=17 coalesced deletes=[CoalescedDeletes(termSets=1,queries=0)] newDelCount=1 100% deleted
   [junit4]   2> 35311 T76 C38 oasu.LoggingInfoStream.message [BD][qtp25819770-76]: applyDeletes took 1 msec
   [junit4]   2> 35311 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: now checkpoint "_2(5.0):C1/1 _3(5.0):C1" [2 segments ; isCommit = false]
   [junit4]   2> 35312 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: 0 msec to checkpoint
   [junit4]   2> 35312 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: drop 100% deleted segments: _2(5.0):C1/1
   [junit4]   2> 35312 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: now checkpoint "_3(5.0):C1" [1 segments ; isCommit = false]
   [junit4]   2> 35312 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: 0 msec to checkpoint
   [junit4]   2> 35313 T76 C38 oasu.LoggingInfoStream.message [BD][qtp25819770-76]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=21 packetCount=1
   [junit4]   2> 35313 T76 C38 oasu.LoggingInfoStream.message [BD][qtp25819770-76]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 35313 T76 C38 oasu.LoggingInfoStream.message [DW][qtp25819770-76]: qtp25819770-76 finishFullFlush success=true
   [junit4]   2> 35314 T76 C38 oasu.LoggingInfoStream.message [TMP][qtp25819770-76]: findMerges: 1 segments
   [junit4]   2> 35314 T76 C38 oasu.LoggingInfoStream.message [TMP][qtp25819770-76]:   seg=_3(5.0):C1 size=0.001 MB [floored]
   [junit4]   2> 35314 T76 C38 oasu.LoggingInfoStream.message [TMP][qtp25819770-76]:   allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
   [junit4]   2> 35315 T76 C38 oasu.LoggingInfoStream.message [CMS][qtp25819770-76]: now merge
   [junit4]   2> 35315 T76 C38 oasu.LoggingInfoStream.message [CMS][qtp25819770-76]:   index: _3(5.0):C1
   [junit4]   2> 35315 T76 C38 oasu.LoggingInfoStream.message [CMS][qtp25819770-76]:   no more merges pending; now return
   [junit4]   2> 35315 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: startCommit(): start
   [junit4]   2> 35316 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: startCommit index=_3(5.0):C1 changeCount=19
   [junit4]   2> 35316 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: done all syncs: [_3.fdx, _3.nvd, _3_Lucene41_0.doc, _3_Lucene41_0.pos, _3_Lucene41_0.tip, _3.si, _3.fdt, _3_Lucene41_0.tim, _3.nvm, _3.fnm]
   [junit4]   2> 35316 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: commit: pendingCommit != null
   [junit4]   2> 35316 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: commit: wrote segments file "segments_6"
   [junit4]   2> 35317 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: now checkpoint "_3(5.0):C1" [1 segments ; isCommit = true]
   [junit4]   2> 35317 T76 C38 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_5,generation=5}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_6,generation=6}
   [junit4]   2> 35317 T76 C38 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
   [junit4]   2> 35317 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: deleteCommits: now decRef commit "segments_5"
   [junit4]   2> 35318 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: delete "_2.si"
   [junit4]   2> 35318 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: delete "_2_Lucene41_0.pos"
   [junit4]   2> 35318 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: unable to remove file "_2_Lucene41_0.pos": java.io.IOException: MockDirectoryWrapper: file "_2_Lucene41_0.pos" is still open: cannot delete; Will re-try later.
   [junit4]   2> 35318 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: delete "_2_Lucene41_0.tim"
   [junit4]   2> 35319 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: unable to remove file "_2_Lucene41_0.tim": java.io.IOException: MockDirectoryWrapper: file "_2_Lucene41_0.tim" is still open: cannot delete; Will re-try later.
   [junit4]   2> 35319 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: delete "_2.nvm"
   [junit4]   2> 35319 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: delete "_2.nvd"
   [junit4]   2> 35319 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: unable to remove file "_2.nvd": java.io.IOException: MockDirectoryWrapper: file "_2.nvd" is still open: cannot delete; Will re-try later.
   [junit4]   2> 35320 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: delete "_2.fdt"
   [junit4]   2> 35320 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: unable to remove file "_2.fdt": java.io.IOException: MockDirectoryWrapper: file "_2.fdt" is still open: cannot delete; Will re-try later.
   [junit4]   2> 35320 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: delete "_2_Lucene41_0.doc"
   [junit4]   2> 35320 T76 C38 oasu.LoggingInf

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

.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
   [junit4]    > 	at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
   [junit4]    > 	at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:717)
   [junit4]    > 	at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:522)
   [junit4]    > 	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
   [junit4]    > 	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
   [junit4]    > 	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
   [junit4]    > 	... 45 more
   [junit4]   2> 241956 T70 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=20669492
   [junit4]   2> 241957 T70 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@670355
   [junit4]   2> 241972 T70 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=69,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=345,cumulative_deletesById=5,cumulative_deletesByQuery=37,cumulative_errors=1}
   [junit4]   2> 241972 T70 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 241972 T70 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 241973 T70 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 241974 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: now flush at close waitForMerges=true
   [junit4]   2> 241974 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]:   start flush: applyAllDeletes=true
   [junit4]   2> 241975 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]:   index before flush 
   [junit4]   2> 241975 T70 C51 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker startFullFlush
   [junit4]   2> 241976 T70 C51 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 241976 T70 C51 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker finishFullFlush success=true
   [junit4]   2> 241977 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: apply all deletes during flush
   [junit4]   2> 241977 T70 C51 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=9223372036854775807 packetCount=0
   [junit4]   2> 241978 T70 C51 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: now merge
   [junit4]   2> 241978 T70 C51 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]:   index: 
   [junit4]   2> 241979 T70 C51 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]:   no more merges pending; now return
   [junit4]   2> 241979 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: waitForMerges
   [junit4]   2> 241980 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: waitForMerges done
   [junit4]   2> 241980 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: now call final commit()
   [junit4]   2> 241980 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: commit: start
   [junit4]   2> 241981 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: commit: enter lock
   [junit4]   2> 241981 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: commit: now prepare
   [junit4]   2> 241981 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: prepareCommit: flush
   [junit4]   2> 241982 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]:   index before flush 
   [junit4]   2> 241982 T70 C51 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker startFullFlush
   [junit4]   2> 241982 T70 C51 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 241982 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: apply all deletes during flush
   [junit4]   2> 241983 T70 C51 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=9223372036854775807 packetCount=0
   [junit4]   2> 241983 T70 C51 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker finishFullFlush success=true
   [junit4]   2> 241983 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: startCommit(): start
   [junit4]   2> 241983 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]:   skip startCommit(): no changes pending
   [junit4]   2> 241984 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: commit: pendingCommit == null; skip
   [junit4]   2> 241984 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: commit: done
   [junit4]   2> 241984 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: at close: 
   [junit4]   2> 241985 T70 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 241985 T70 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 241985 T70 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911;done=false>>]
   [junit4]   2> 241985 T70 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911
   [junit4]   2> 241986 T70 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911/index;done=false>>]
   [junit4]   2> 241986 T70 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911/index
   [junit4]   2> 241986 T70 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 242038 T70 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene45: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=lv, timezone=Australia/Queensland
   [junit4]   2> NOTE: Linux 3.2.0-52-generic i386/Oracle Corporation 1.8.0-ea (32-bit)/cpus=8,threads=1,free=23191048,total=64880640
   [junit4]   2> NOTE: All tests run in this JVM: [SolrExampleBinaryTest, SolrExampleStreamingTest, SolrExampleJettyTest]
   [junit4] Completed on J1 in 207.97s, 27 tests, 1 error <<< FAILURES!

[...truncated 34 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:396: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:376: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:202: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:455: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1230: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:873: There were test failures: 46 suites, 272 tests, 1 error

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



Mime
View raw message