You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/08/11 21:40:51 UTC
[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.6.0) - Build # 702 -
Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/702/
Java: 64bit/jdk1.6.0 -XX:+UseCompressedOops -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.client.solrj.embedded.SolrExampleJettyTest.testAddDelete
Error Message:
IOException occured when talking to server at: https://127.0.0.1:55300/solr/collection1
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:55300/solr/collection1
at __randomizedtesting.SeedInfo.seed([F2078D00D4BA7149:3AE7F00A2512A29F]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:435)
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.testAddDelete(SolrExampleTests.java:737)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
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:680)
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 10202 lines...]
[junit4] Suite: org.apache.solr.client.solrj.embedded.SolrExampleJettyTest
[junit4] 2> 202234 T474 oas.SolrJettyTestBase.beforeSolrJettyTestBase Randomized ssl (true) and clientAuth (false)
[junit4] 2> 202239 T474 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/./solrtest-SolrExampleJettyTest-1376249694218
[junit4] 2> 202240 T474 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 202241 T474 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 202317 T474 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1] of [SSLv2Hello, SSLv3, TLSv1]
[junit4] 2> 202338 T474 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:55300
[junit4] 2> 202339 T474 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 202339 T474 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 202339 T474 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr
[junit4] 2> 202340 T474 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/'
[junit4] 2> 202391 T474 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/solr.xml
[junit4] 2> 202509 T474 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 202514 T474 oasc.CoreContainer.<init> New CoreContainer 286764692
[junit4] 2> 202514 T474 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/]
[junit4] 2> 202516 T474 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 202516 T474 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 202517 T474 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 202517 T474 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 202517 T474 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 202518 T474 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 202518 T474 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 202519 T474 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 202519 T474 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 202519 T474 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 202553 T474 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr
[junit4] 2> 202573 T474 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/
[junit4] 2> 202574 T474 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 202585 T484 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1
[junit4] 2> 202586 T484 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/'
[junit4] 2> 202637 T484 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 202638 T484 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/extraction/lib (resolved as: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/../../../contrib/extraction/lib).
[junit4] 2> 202639 T484 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/../../../dist).
[junit4] 2> 202640 T484 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/clustering/lib/ (resolved as: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/../../../contrib/clustering/lib).
[junit4] 2> 202640 T484 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/../../../dist).
[junit4] 2> 202641 T484 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/langid/lib/ (resolved as: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/../../../contrib/langid/lib).
[junit4] 2> 202641 T484 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/../../../dist).
[junit4] 2> 202642 T484 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/velocity/lib (resolved as: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/../../../contrib/velocity/lib).
[junit4] 2> 202642 T484 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/../../../dist).
[junit4] 2> 202736 T484 oasu.SolrIndexConfig.<init> IndexWriter infoStream solr logging is enabled
[junit4] 2> 202745 T484 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 202955 T484 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 202956 T484 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 202999 T484 oass.IndexSchema.readSchema [collection1] Schema name=example
[junit4] 2> 203922 T484 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 204035 T484 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 204044 T484 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 204086 T484 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 204087 T484 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleJettyTest-1376249694218/
[junit4] 2> 204087 T484 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@53601a4f
[junit4] 2> 204093 T484 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4] 2> 204094 T484 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
[junit4] 2> 204095 T484 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleJettyTest-1376249694218
[junit4] 2> 204095 T484 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleJettyTest-1376249694218/index/
[junit4] 2> 204096 T484 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleJettyTest-1376249694218/index' doesn't exist. Creating new index...
[junit4] 2> 204096 T484 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleJettyTest-1376249694218/index
[junit4] 2> 204098 T484 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-245-thread-1]: init: current segments file is "null"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@75bf48de
[junit4] 2> 204098 T484 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-245-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 204099 T484 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-245-thread-1]: 0 msec to checkpoint
[junit4] 2> 204099 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: init: create=true
[junit4] 2> 204099 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]:
[junit4] 2> dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6cb2b9ec lockFactory=org.apache.lucene.store.NativeFSLockFactory@72402ecb)
[junit4] 2> index=
[junit4] 2> version=4.5-SNAPSHOT
[junit4] 2> matchVersion=LUCENE_45
[junit4] 2> analyzer=null
[junit4] 2> ramBufferSizeMB=100.0
[junit4] 2> maxBufferedDocs=-1
[junit4] 2> maxBufferedDeleteTerms=-1
[junit4] 2> mergedSegmentWarmer=null
[junit4] 2> readerTermsIndexDivisor=1
[junit4] 2> termIndexInterval=32
[junit4] 2> delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
[junit4] 2> commit=null
[junit4] 2> openMode=CREATE
[junit4] 2> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
[junit4] 2> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
[junit4] 2> default WRITE_LOCK_TIMEOUT=1000
[junit4] 2> writeLockTimeout=1000
[junit4] 2> codec=Lucene42
[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@61492336
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2>
[junit4] 2> 204100 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: now flush at close waitForMerges=true
[junit4] 2> 204100 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: start flush: applyAllDeletes=true
[junit4] 2> 204100 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: index before flush
[junit4] 2> 204101 T484 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-245-thread-1]: coreLoadExecutor-245-thread-1 startFullFlush
[junit4] 2> 204101 T484 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-245-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204101 T484 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-245-thread-1]: coreLoadExecutor-245-thread-1 finishFullFlush success=true
[junit4] 2> 204102 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: apply all deletes during flush
[junit4] 2> 204102 T484 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-245-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@8a6e020 minGen=9223372036854775807 packetCount=0
[junit4] 2> 204102 T484 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-245-thread-1]: now merge
[junit4] 2> 204103 T484 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-245-thread-1]: index:
[junit4] 2> 204103 T484 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-245-thread-1]: no more merges pending; now return
[junit4] 2> 204103 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: waitForMerges
[junit4] 2> 204103 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: waitForMerges done
[junit4] 2> 204104 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: now call final commit()
[junit4] 2> 204104 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: commit: start
[junit4] 2> 204104 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: commit: enter lock
[junit4] 2> 204105 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: commit: now prepare
[junit4] 2> 204105 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: prepareCommit: flush
[junit4] 2> 204105 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: index before flush
[junit4] 2> 204106 T484 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-245-thread-1]: coreLoadExecutor-245-thread-1 startFullFlush
[junit4] 2> 204106 T484 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-245-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204106 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: apply all deletes during flush
[junit4] 2> 204107 T484 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-245-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@8a6e020 minGen=9223372036854775807 packetCount=0
[junit4] 2> 204107 T484 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-245-thread-1]: coreLoadExecutor-245-thread-1 finishFullFlush success=true
[junit4] 2> 204107 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: startCommit(): start
[junit4] 2> 204112 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: startCommit index= changeCount=1
[junit4] 2> 204113 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: done all syncs: []
[junit4] 2> 204113 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: commit: pendingCommit != null
[junit4] 2> 204113 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: commit: wrote segments file "segments_1"
[junit4] 2> 204114 T484 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-245-thread-1]: now checkpoint "" [0 segments ; isCommit = true]
[junit4] 2> 204114 T484 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6cb2b9ec lockFactory=org.apache.lucene.store.NativeFSLockFactory@72402ecb),segFN=segments_1,generation=1}
[junit4] 2> 204114 T484 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 204115 T484 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-245-thread-1]: 1 msec to checkpoint
[junit4] 2> 204116 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: commit: done
[junit4] 2> 204116 T484 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-245-thread-1]: at close:
[junit4] 2> 204117 T484 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 204117 T484 oasc.SolrCore.initWriters adding lazy queryResponseWriter: solr.VelocityResponseWriter
[junit4] 2> 204118 T484 oasc.SolrCore.initWriters created velocity: solr.VelocityResponseWriter
[junit4] 2> 204118 T484 oasc.SolrCore.initWriters created xslt: solr.XSLTResponseWriter
[junit4] 2> 204118 T484 oasr.XSLTResponseWriter.init xsltCacheLifetimeSeconds=5
[junit4] 2> 204132 T484 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 204133 T484 oasc.RequestHandlers.initHandlersFromConfig created /query: solr.SearchHandler
[junit4] 2> 204134 T484 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 204135 T484 oasc.RequestHandlers.initHandlersFromConfig created /browse: solr.SearchHandler
[junit4] 2> 204135 T484 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 204136 T484 oasc.RequestHandlers.initHandlersFromConfig created /update/json: solr.JsonUpdateRequestHandler
[junit4] 2> 204137 T484 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: solr.CSVRequestHandler
[junit4] 2> 204138 T484 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
[junit4] 2> 204138 T484 oasc.RequestHandlers.initHandlersFromConfig created /update/extract: solr.extraction.ExtractingRequestHandler
[junit4] 2> 204138 T484 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.FieldAnalysisRequestHandler
[junit4] 2> 204139 T484 oasc.RequestHandlers.initHandlersFromConfig created /analysis/field: solr.FieldAnalysisRequestHandler
[junit4] 2> 204139 T484 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
[junit4] 2> 204140 T484 oasc.RequestHandlers.initHandlersFromConfig created /analysis/document: solr.DocumentAnalysisRequestHandler
[junit4] 2> 204141 T484 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 204142 T484 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
[junit4] 2> 204143 T484 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 204144 T484 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 204144 T484 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 204148 T484 oasc.RequestHandlers.initHandlersFromConfig created /spell: solr.SearchHandler
[junit4] 2> 204148 T484 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 204149 T484 oasc.RequestHandlers.initHandlersFromConfig created /tvrh: solr.SearchHandler
[junit4] 2> 204149 T484 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 204150 T484 oasc.RequestHandlers.initHandlersFromConfig created /terms: solr.SearchHandler
[junit4] 2> 204150 T484 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 204150 T484 oasc.RequestHandlers.initHandlersFromConfig created /elevate: solr.SearchHandler
[junit4] 2> 204167 T484 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 204169 T484 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 204171 T484 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 204179 T484 oass.SolrIndexSearcher.<init> Opening Searcher@617de0a8 main
[junit4] 2> 204181 T484 oasu.CommitTracker.<init> Hard AutoCommit: if uncommited for 15000ms;
[junit4] 2> 204181 T484 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 204182 T484 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 204182 T484 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> 204183 T484 oashc.SpellCheckComponent.inform No queryConverter defined, using default converter
[junit4] 2> 204184 T484 oashc.QueryElevationComponent.inform Loading QueryElevation from: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/conf/elevate.xml
[junit4] 2> 204239 T484 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 204239 T485 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@617de0a8 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> ASYNC NEW_CORE C77 name=collection1 org.apache.solr.core.SolrCore@2ac28d29
[junit4] 2> 204241 T485 C77 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> 204241 T485 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 204242 T485 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
[junit4] 2> 204242 T485 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
[junit4] 2> 204245 T485 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@617de0a8 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 204254 T484 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 204257 T474 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0
[junit4] 2> 204257 T474 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 204258 T474 oas.SolrJettyTestBase.createJetty Jetty Assigned Port#55300
[junit4] 2> 204271 T474 oas.SolrTestCaseJ4.setUp ###Starting testMultiContentStreamRequest
[junit4] 2> 204271 T474 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 204350 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: init: current segments file is "segments_1"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@75bf48de
[junit4] 2> 204351 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: init: load commit "segments_1"
[junit4] 2> 204351 T479 C77 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6cb2b9ec lockFactory=org.apache.lucene.store.NativeFSLockFactory@72402ecb),segFN=segments_1,generation=1}
[junit4] 2> 204352 T479 C77 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 204353 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 204353 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: 0 msec to checkpoint
[junit4] 2> 204354 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]: init: create=false
[junit4] 2> 204354 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]:
[junit4] 2> dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6cb2b9ec lockFactory=org.apache.lucene.store.NativeFSLockFactory@72402ecb)
[junit4] 2> index=
[junit4] 2> version=4.5-SNAPSHOT
[junit4] 2> matchVersion=LUCENE_45
[junit4] 2> analyzer=null
[junit4] 2> ramBufferSizeMB=100.0
[junit4] 2> maxBufferedDocs=-1
[junit4] 2> maxBufferedDeleteTerms=-1
[junit4] 2> mergedSegmentWarmer=null
[junit4] 2> readerTermsIndexDivisor=1
[junit4] 2> termIndexInterval=32
[junit4] 2> delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
[junit4] 2> commit=null
[junit4] 2> openMode=APPEND
[junit4] 2> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
[junit4] 2> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
[junit4] 2> default WRITE_LOCK_TIMEOUT=1000
[junit4] 2> writeLockTimeout=1000
[junit4] 2> codec=Lucene42
[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@70bd61d4
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2>
[junit4] 2> 204357 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]: flush at getReader
[junit4] 2> 204357 T479 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-479]: qtp1415138589-479 startFullFlush
[junit4] 2> 204358 T479 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-479]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204358 T479 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-479]: qtp1415138589-479: flush naked frozen global deletes
[junit4] 2> 204360 T479 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-479]: push deletes 1 deleted queries bytesUsed=32 delGen=1 packetCount=1 totBytesUsed=32
[junit4] 2> 204363 T479 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-479]: flush: push buffered deletes: 1 deleted queries bytesUsed=32
[junit4] 2> 204366 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]: apply all deletes during flush
[junit4] 2> 204366 T479 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-479]: prune sis=org.apache.lucene.index.SegmentInfos@207f7d58 minGen=9223372036854775807 packetCount=1
[junit4] 2> 204366 T479 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-479]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 204367 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
[junit4] 2> 204367 T479 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-479]: qtp1415138589-479 finishFullFlush success=true
[junit4] 2> 204368 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]: getReader took 11 msec
[junit4] 2> 204368 T479 C77 oass.SolrIndexSearcher.<init> Opening Searcher@4641439f realtime
[junit4] 2> 204369 T479 C77 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1443102401573683200)} 0 23
[junit4] 2> 204375 T480 C77 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 204376 T480 C77 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 204377 T480 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-480]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204377 T480 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-480]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
[junit4] 2> 204378 T480 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-480]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204378 T480 C77 oass.SolrIndexSearcher.<init> Opening Searcher@170e3e70 main
[junit4] 2> 204380 T480 C77 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 204381 T485 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@170e3e70 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 204381 T485 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 204385 T485 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@170e3e70 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 204386 T480 C77 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 11
[junit4] 2> 204393 T481 C77 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=1
[junit4] 2> 204426 T482 C77 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 204427 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: commit: start
[junit4] 2> 204427 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: commit: enter lock
[junit4] 2> 204427 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: commit: now prepare
[junit4] 2> 204428 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: prepareCommit: flush
[junit4] 2> 204429 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: index before flush
[junit4] 2> 204429 T482 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-482]: qtp1415138589-482 startFullFlush
[junit4] 2> 204431 T482 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-482]: anyChanges? numDocsInRam=5 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204434 T482 C77 oasu.LoggingInfoStream.message [DWFC][qtp1415138589-482]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 4 deleted terms (unique count=4) bytesUsed=699, segment=_0, aborting=false, numDocsInRAM=5, deleteQueue=DWDQ: [ generation: 1 ]]
[junit4] 2> 204436 T482 C77 oasu.LoggingInfoStream.message [DWPT][qtp1415138589-482]: flush postings as segment _0 numDocs=5
[junit4] 2> 204443 T482 C77 oasu.LoggingInfoStream.message [DWPT][qtp1415138589-482]: new segment has 0 deleted docs
[junit4] 2> 204444 T482 C77 oasu.LoggingInfoStream.message [DWPT][qtp1415138589-482]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 204444 T482 C77 oasu.LoggingInfoStream.message [DWPT][qtp1415138589-482]: flushedFiles=[_0_Lucene41_0.pay, _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> 204445 T482 C77 oasu.LoggingInfoStream.message [DWPT][qtp1415138589-482]: flushed codec=Lucene42
[junit4] 2> 204446 T482 C77 oasu.LoggingInfoStream.message [DWPT][qtp1415138589-482]: flushed: segment=_0 ramUsed=0.115 MB newFlushedSize(includes docstores)=0.007 MB docs/MB=728.785
[junit4] 2> 204446 T482 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-482]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 204447 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: publishFlushedSegment
[junit4] 2> 204448 T482 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-482]: push deletes 5 deleted terms (unique count=5) bytesUsed=1024 delGen=3 packetCount=1 totBytesUsed=1024
[junit4] 2> 204448 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: publish sets newSegment delGen=4 seg=_0(4.5):C5
[junit4] 2> 204449 T482 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-482]: now checkpoint "_0(4.5):C5" [1 segments ; isCommit = false]
[junit4] 2> 204450 T482 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-482]: 0 msec to checkpoint
[junit4] 2> 204450 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: apply all deletes during flush
[junit4] 2> 204451 T482 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-482]: applyDeletes: infos=[_0(4.5):C5] packetCount=1
[junit4] 2> 204451 T482 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-482]: applyDeletes took 0 msec
[junit4] 2> 204452 T482 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-482]: prune sis=org.apache.lucene.index.SegmentInfos@207f7d58 minGen=5 packetCount=1
[junit4] 2> 204452 T482 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-482]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 204453 T482 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-482]: qtp1415138589-482 finishFullFlush success=true
[junit4] 2> 204453 T482 C77 oasu.LoggingInfoStream.message [TMP][qtp1415138589-482]: findMerges: 1 segments
[junit4] 2> 204454 T482 C77 oasu.LoggingInfoStream.message [TMP][qtp1415138589-482]: seg=_0(4.5):C5 size=0.007 MB [floored]
[junit4] 2> 204455 T482 C77 oasu.LoggingInfoStream.message [TMP][qtp1415138589-482]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 204455 T482 C77 oasu.LoggingInfoStream.message [CMS][qtp1415138589-482]: now merge
[junit4] 2> 204456 T482 C77 oasu.LoggingInfoStream.message [CMS][qtp1415138589-482]: index: _0(4.5):C5
[junit4] 2> 204456 T482 C77 oasu.LoggingInfoStream.message [CMS][qtp1415138589-482]: no more merges pending; now return
[junit4] 2> 204457 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: startCommit(): start
[junit4] 2> 204457 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: startCommit index=_0(4.5):C5 changeCount=3
[junit4] 2> 204458 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: done all syncs: [_0_Lucene41_0.pay, _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> 204458 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: commit: pendingCommit != null
[junit4] 2> 204459 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: commit: wrote segments file "segments_2"
[junit4] 2> 204460 T482 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-482]: now checkpoint "_0(4.5):C5" [1 segments ; isCommit = true]
[junit4] 2> 204460 T482 C77 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6cb2b9ec lockFactory=org.apache.lucene.store.NativeFSLockFactory@72402ecb),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6cb2b9ec lockFactory=org.apache.lucene.store.NativeFSLockFactory@72402ecb),segFN=segments_2,generation=2}
[junit4] 2> 204461 T482 C77 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 204461 T482 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-482]: deleteCommits: now decRef commit "segments_1"
[junit4] 2> 204462 T482 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-482]: delete "segments_1"
[junit4] 2> 204462 T482 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-482]: 2 msec to checkpoint
[junit4] 2> 204463 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: commit: done
[junit4] 2> 204464 T482 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-482]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204464 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 204465 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: flush at getReader
[junit4] 2> 204465 T482 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-482]: qtp1415138589-482 startFullFlush
[junit4] 2> 204466 T482 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-482]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204466 T482 C77 oasu.LoggingInfoStream.message [DWFC][qtp1415138589-482]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 2 ]]
[junit4] 2> 204467 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: apply all deletes during flush
[junit4] 2> 204468 T482 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-482]: applyDeletes: no deletes; skipping
[junit4] 2> 204469 T482 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-482]: prune sis=org.apache.lucene.index.SegmentInfos@207f7d58 minGen=5 packetCount=0
[junit4] 2> 204472 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: return reader version=3 reader=StandardDirectoryReader(segments_2:3:nrt _0(4.5):C5)
[junit4] 2> 204472 T482 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-482]: qtp1415138589-482 finishFullFlush success=true
[junit4] 2> 204473 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: getReader took 8 msec
[junit4] 2> 204473 T482 C77 oass.SolrIndexSearcher.<init> Opening Searcher@4e7016ff main
[junit4] 2> 204474 T482 C77 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 204474 T485 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@4e7016ff main{StandardDirectoryReader(segments_2:3:nrt _0(4.5):C5)}
[junit4] 2> 204475 T485 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 204479 T485 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4e7016ff main{StandardDirectoryReader(segments_2:3:nrt _0(4.5):C5)}
[junit4] 2> 204480 T482 C77 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&echoParams=ALL&commit=true&a=?&wt=javabin&version=2&softCommit=false} {add=[SP2514N (1443102401639743488), 6H500F0 (1443102401644986368), TWINX2048-3200PRO (1443102401648132096), VS1GB400C3 (1443102401651277824), VDBDB1A16 (1443102401654423552)],commit=} 0 71
[junit4] 2> 204487 T483 C77 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=5 status=0 QTime=1
[junit4] 2> 204490 T474 oas.SolrTestCaseJ4.tearDown ###Ending testMultiContentStreamRequest
[junit4] 2> 204508 T474 oas.SolrTestCaseJ4.setUp ###Starting testFaceting
[junit4] 2> 204514 T478 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-478]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204514 T478 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-478]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 204515 T478 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-478]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204515 T478 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-478]: flush at getReader
[junit4] 2> 204516 T478 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-478]: qtp1415138589-478 startFullFlush
[junit4] 2> 204516 T478 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-478]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204517 T478 C77 oasu.LoggingInfoStream.message [DWFC][qtp1415138589-478]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 3 ]]
[junit4] 2> 204517 T478 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-478]: qtp1415138589-478: flush naked frozen global deletes
[junit4] 2> 204518 T478 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-478]: push deletes 1 deleted queries bytesUsed=32 delGen=7 packetCount=1 totBytesUsed=32
[junit4] 2> 204519 T478 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-478]: flush: push buffered deletes: 1 deleted queries bytesUsed=32
[junit4] 2> 204520 T478 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-478]: apply all deletes during flush
[junit4] 2> 204520 T478 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-478]: applyDeletes: infos=[_0(4.5):C5] packetCount=1
[junit4] 2> 204524 T478 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-478]: seg=_0(4.5):C5 segGen=5 coalesced deletes=[CoalescedDeletes(termSets=1,queries=1)] newDelCount=5 100% deleted
[junit4] 2> 204524 T478 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-478]: applyDeletes took 4 msec
[junit4] 2> 204525 T478 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-478]: now checkpoint "_0(4.5):C5/5" [1 segments ; isCommit = false]
[junit4] 2> 204526 T478 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-478]: 0 msec to checkpoint
[junit4] 2> 204526 T478 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-478]: drop 100% deleted segments: _0(4.5):C5/5
[junit4] 2> 204527 T478 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-478]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 204527 T478 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-478]: 0 msec to checkpoint
[junit4] 2> 204528 T478 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-478]: prune sis=org.apache.lucene.index.SegmentInfos@207f7d58 minGen=9223372036854775807 packetCount=1
[junit4] 2> 204528 T478 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-478]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 204529 T478 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-478]: return reader version=5 reader=StandardDirectoryReader(segments_2:5:nrt)
[junit4] 2> 204529 T478 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-478]: qtp1415138589-478 finishFullFlush success=true
[junit4] 2> 204530 T478 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-478]: getReader took 15 msec
[junit4] 2> 204531 T478 C77 oass.SolrIndexSearcher.<init> Opening Searcher@60532b8 realtime
[junit4] 2> 204531 T478 C77 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1443102401746698240)} 0 19
[junit4] 2> 204537 T479 C77 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 204537 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]: commit: start
[junit4] 2> 204538 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]: commit: enter lock
[junit4] 2> 204538 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]: commit: now prepare
[junit4] 2> 204539 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]: prepareCommit: flush
[junit4] 2> 204539 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]: index before flush
[junit4] 2> 204540 T479 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-479]: qtp1415138589-479 startFullFlush
[junit4] 2> 204540 T479 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-479]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204541 T479 C77 oasu.LoggingInfoStream.message [DWFC][qtp1415138589-479]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 4 ]]
[junit4] 2> 204541 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]: apply all deletes during flush
[junit4] 2> 204542 T479 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-479]: prune sis=org.apache.lucene.index.SegmentInfos@207f7d58 minGen=9223372036854775807 packetCount=0
[junit4] 2> 204542 T479 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-479]: qtp1415138589-479 finishFullFlush success=true
[junit4] 2> 204543 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]: startCommit(): start
[junit4] 2> 204543 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]: startCommit index= changeCount=6
[junit4] 2> 204544 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]: done all syncs: []
[junit4] 2> 204544 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]: commit: pendingCommit != null
[junit4] 2> 204545 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]: commit: wrote segments file "segments_3"
[junit4] 2> 204546 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: now checkpoint "" [0 segments ; isCommit = true]
[junit4] 2> 204546 T479 C77 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6cb2b9ec lockFactory=org.apache.lucene.store.NativeFSLockFactory@72402ecb),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6cb2b9ec lockFactory=org.apache.lucene.store.NativeFSLockFactory@72402ecb),segFN=segments_3,generation=3}
[junit4] 2> 204547 T479 C77 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 204547 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: deleteCommits: now decRef commit "segments_2"
[junit4] 2> 204548 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: delete "_0_Lucene41_0.pay"
[junit4] 2> 204549 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: unable to remove file "_0_Lucene41_0.pay": java.io.IOException: MockDirectoryWrapper: file "_0_Lucene41_0.pay" is still open: cannot delete; Will re-try later.
[junit4] 2> 204549 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: delete "_0.fnm"
[junit4] 2> 204550 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: delete "_0_Lucene41_0.doc"
[junit4] 2> 204550 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: 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> 204551 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: delete "_0_Lucene41_0.pos"
[junit4] 2> 204551 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: 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> 204552 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: delete "_0.nvd"
[junit4] 2> 204552 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: unable to remove file "_0.nvd": java.io.IOException: MockDirectoryWrapper: file "_0.nvd" is still open: cannot delete; Will re-try later.
[junit4] 2> 204553 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: delete "segments_2"
[junit4] 2> 204554 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: delete "_0.fdx"
[junit4] 2> 204557 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: delete "_0.si"
[junit4] 2> 204559 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: delete "_0.nvm"
[junit4] 2> 204560 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: delete "_0_Lucene41_0.tim"
[junit4] 2> 204561 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: 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> 204561 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: delete "_0.fdt"
[junit4] 2> 204562 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: unable to remove file "_0.fdt": java.io.IOException: MockDirectoryWrapper: file "_0.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 204562 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: delete "_0_Lucene41_0.tip"
[junit4] 2> 204563 T479 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-479]: 17 msec to checkpoint
[junit4] 2> 204563 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]: commit: done
[junit4] 2> 204564 T479 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-479]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204567 T479 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-479]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
[junit4] 2> 204568 T479 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-479]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204568 T479 C77 oass.SolrIndexSearcher.<init> Opening Searcher@4a15d117 main
[junit4] 2> 204569 T479 C77 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 204569 T485 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@4a15d117 main{StandardDirectoryReader(segments_2:5:nrt)}
[junit4] 2> 204570 T485 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 204573 T485 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4a15d117 main{StandardDirectoryReader(segments_2:5:nrt)}
[junit4] 2> 204574 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete pending file _0_Lucene41_0.pay
[junit4] 2> 204574 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete "_0_Lucene41_0.pay"
[junit4] 2> 204575 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete pending file _0_Lucene41_0.doc
[junit4] 2> 204575 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete "_0_Lucene41_0.doc"
[junit4] 2> 204575 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete pending file _0_Lucene41_0.pos
[junit4] 2> 204576 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete "_0_Lucene41_0.pos"
[junit4] 2> 204576 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete pending file _0.nvd
[junit4] 2> 204576 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete "_0.nvd"
[junit4] 2> 204577 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete pending file _0_Lucene41_0.tim
[junit4] 2> 204577 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete "_0_Lucene41_0.tim"
[junit4] 2> 204577 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete pending file _0.fdt
[junit4] 2> 204578 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete "_0.fdt"
[junit4] 2> 204578 T479 C77 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 41
[junit4] 2> 204583 T480 C77 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 204600 T481 C77 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1 (1443102401829535744), 2 (1443102401833730048), 3 (1443102401834778624), 4 (1443102401835827200), 5 (1443102401835827201), 6 (1443102401836875776), 7 (1443102401836875777), 8 (1443102401836875778), 9 (1443102401837924352), 10 (1443102401837924353)]} 0 11
[junit4] 2> 204606 T482 C77 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 204607 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: commit: start
[junit4] 2> 204607 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: commit: enter lock
[junit4] 2> 204610 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: commit: now prepare
[junit4] 2> 204610 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: prepareCommit: flush
[junit4] 2> 204610 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: index before flush
[junit4] 2> 204611 T482 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-482]: qtp1415138589-482 startFullFlush
[junit4] 2> 204611 T482 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-482]: anyChanges? numDocsInRam=10 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204612 T482 C77 oasu.LoggingInfoStream.message [DWFC][qtp1415138589-482]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 9 deleted terms (unique count=9) bytesUsed=1486, segment=_1, aborting=false, numDocsInRAM=10, deleteQueue=DWDQ: [ generation: 5 ]]
[junit4] 2> 204612 T482 C77 oasu.LoggingInfoStream.message [DWPT][qtp1415138589-482]: flush postings as segment _1 numDocs=10
[junit4] 2> 204615 T482 C77 oasu.LoggingInfoStream.message [DWPT][qtp1415138589-482]: new segment has 0 deleted docs
[junit4] 2> 204615 T482 C77 oasu.LoggingInfoStream.message [DWPT][qtp1415138589-482]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 204615 T482 C77 oasu.LoggingInfoStream.message [DWPT][qtp1415138589-482]: 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> 204616 T482 C77 oasu.LoggingInfoStream.message [DWPT][qtp1415138589-482]: flushed codec=Lucene42
[junit4] 2> 204617 T482 C77 oasu.LoggingInfoStream.message [DWPT][qtp1415138589-482]: flushed: segment=_1 ramUsed=0.081 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=7,670.636
[junit4] 2> 204617 T482 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-482]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 204618 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: publishFlushedSegment
[junit4] 2> 204618 T482 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-482]: push deletes 10 deleted terms (unique count=10) bytesUsed=1024 delGen=10 packetCount=1 totBytesUsed=1024
[junit4] 2> 204619 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: publish sets newSegment delGen=11 seg=_1(4.5):C10
[junit4] 2> 204619 T482 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-482]: now checkpoint "_1(4.5):C10" [1 segments ; isCommit = false]
[junit4] 2> 204620 T482 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-482]: 0 msec to checkpoint
[junit4] 2> 204620 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: apply all deletes during flush
[junit4] 2> 204621 T482 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-482]: applyDeletes: infos=[_1(4.5):C10] packetCount=1
[junit4] 2> 204621 T482 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-482]: applyDeletes took 0 msec
[junit4] 2> 204621 T482 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-482]: prune sis=org.apache.lucene.index.SegmentInfos@207f7d58 minGen=12 packetCount=1
[junit4] 2> 204623 T482 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-482]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 204628 T482 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-482]: qtp1415138589-482 finishFullFlush success=true
[junit4] 2> 204629 T482 C77 oasu.LoggingInfoStream.message [TMP][qtp1415138589-482]: findMerges: 1 segments
[junit4] 2> 204630 T482 C77 oasu.LoggingInfoStream.message [TMP][qtp1415138589-482]: seg=_1(4.5):C10 size=0.001 MB [floored]
[junit4] 2> 204630 T482 C77 oasu.LoggingInfoStream.message [TMP][qtp1415138589-482]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 204633 T482 C77 oasu.LoggingInfoStream.message [CMS][qtp1415138589-482]: now merge
[junit4] 2> 204633 T482 C77 oasu.LoggingInfoStream.message [CMS][qtp1415138589-482]: index: _1(4.5):C10
[junit4] 2> 204634 T482 C77 oasu.LoggingInfoStream.message [CMS][qtp1415138589-482]: no more merges pending; now return
[junit4] 2> 204634 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: startCommit(): start
[junit4] 2> 204634 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: startCommit index=_1(4.5):C10 changeCount=9
[junit4] 2> 204635 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: 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> 204636 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: commit: pendingCommit != null
[junit4] 2> 204636 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: commit: wrote segments file "segments_4"
[junit4] 2> 204637 T482 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-482]: now checkpoint "_1(4.5):C10" [1 segments ; isCommit = true]
[junit4] 2> 204637 T482 C77 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6cb2b9ec lockFactory=org.apache.lucene.store.NativeFSLockFactory@72402ecb),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6cb2b9ec lockFactory=org.apache.lucene.store.NativeFSLockFactory@72402ecb),segFN=segments_4,generation=4}
[junit4] 2> 204638 T482 C77 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 204638 T482 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-482]: deleteCommits: now decRef commit "segments_3"
[junit4] 2> 204638 T482 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-482]: delete "segments_3"
[junit4] 2> 204639 T482 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-482]: 2 msec to checkpoint
[junit4] 2> 204639 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: commit: done
[junit4] 2> 204640 T482 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-482]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204640 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 204641 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: flush at getReader
[junit4] 2> 204641 T482 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-482]: qtp1415138589-482 startFullFlush
[junit4] 2> 204641 T482 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-482]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204642 T482 C77 oasu.LoggingInfoStream.message [DWFC][qtp1415138589-482]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 6 ]]
[junit4] 2> 204642 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: apply all deletes during flush
[junit4] 2> 204642 T482 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-482]: applyDeletes: no deletes; skipping
[junit4] 2> 204643 T482 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-482]: prune sis=org.apache.lucene.index.SegmentInfos@207f7d58 minGen=12 packetCount=0
[junit4] 2> 204645 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: return reader version=7 reader=StandardDirectoryReader(segments_4:7:nrt _1(4.5):C10)
[junit4] 2> 204645 T482 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-482]: qtp1415138589-482 finishFullFlush success=true
[junit4] 2> 204646 T482 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-482]: getReader took 5 msec
[junit4] 2> 204646 T482 C77 oass.SolrIndexSearcher.<init> Opening Searcher@52c62074 main
[junit4] 2> 204647 T482 C77 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 204647 T485 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@52c62074 main{StandardDirectoryReader(segments_4:7:nrt _1(4.5):C10)}
[junit4] 2> 204647 T485 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 204650 T485 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@52c62074 main{StandardDirectoryReader(segments_4:7:nrt _1(4.5):C10)}
[junit4] 2> 204651 T482 C77 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 45
[junit4] 2> 204662 T483 C77 oasr.UnInvertedField.<init> UnInverted multi-valued field {field=features,memSize=4564,tindexSize=44,time=1,phase1=1,nTerms=4,bigTerms=2,termInstances=4,uses=0}
[junit4] 2> 204662 T483 C77 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=2
[junit4] 2> 204668 T478 C77 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> 204675 T479 C77 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=3
[junit4] 2> 204680 T480 C77 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> 204682 T474 oas.SolrTestCaseJ4.tearDown ###Ending testFaceting
[junit4] 2> 204701 T474 oas.SolrTestCaseJ4.setUp ###Starting testRealtimeGet
[junit4] 2> 204706 T481 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-481]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204706 T481 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-481]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 204707 T481 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-481]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204708 T481 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-481]: flush at getReader
[junit4] 2> 204708 T481 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-481]: qtp1415138589-481 startFullFlush
[junit4] 2> 204708 T481 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-481]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204709 T481 C77 oasu.LoggingInfoStream.message [DWFC][qtp1415138589-481]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 7 ]]
[junit4] 2> 204709 T481 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-481]: qtp1415138589-481: flush naked frozen global deletes
[junit4] 2> 204710 T481 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-481]: push deletes 1 deleted queries bytesUsed=32 delGen=14 packetCount=1 totBytesUsed=32
[junit4] 2> 204710 T481 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-481]: flush: push buffered deletes: 1 deleted queries bytesUsed=32
[junit4] 2> 204711 T481 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-481]: apply all deletes during flush
[junit4] 2> 204711 T481 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-481]: applyDeletes: infos=[_1(4.5):C10] packetCount=1
[junit4] 2> 204712 T481 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-481]: seg=_1(4.5):C10 segGen=12 coalesced deletes=[CoalescedDeletes(termSets=1,queries=1)] newDelCount=10 100% deleted
[junit4] 2> 204712 T481 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-481]: applyDeletes took 1 msec
[junit4] 2> 204713 T481 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-481]: now checkpoint "_1(4.5):C10/10" [1 segments ; isCommit = false]
[junit4] 2> 204713 T481 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-481]: 0 msec to checkpoint
[junit4] 2> 204714 T481 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-481]: drop 100% deleted segments: _1(4.5):C10/10
[junit4] 2> 204714 T481 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-481]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 204715 T481 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-481]: 1 msec to checkpoint
[junit4] 2> 204716 T481 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-481]: prune sis=org.apache.lucene.index.SegmentInfos@207f7d58 minGen=9223372036854775807 packetCount=1
[junit4] 2> 204717 T481 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-481]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 204718 T481 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-481]: return reader version=9 reader=StandardDirectoryReader(segments_4:9:nrt)
[junit4] 2> 204718 T481 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-481]: qtp1415138589-481 finishFullFlush success=true
[junit4] 2> 204720 T481 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-481]: getReader took 12 msec
[junit4] 2> 204724 T481 C77 oass.SolrIndexSearcher.<init> Opening Searcher@aa85638 realtime
[junit4] 2> 204725 T481 C77 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1443102401948024832)} 0 21
[junit4] 2> 204731 T482 C77 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[DOCID (1443102401975287808)]} 0 2
[junit4] 2> 204735 T483 C77 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 204735 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: commit: start
[junit4] 2> 204735 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: commit: enter lock
[junit4] 2> 204736 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: commit: now prepare
[junit4] 2> 204736 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: prepareCommit: flush
[junit4] 2> 204739 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: index before flush
[junit4] 2> 204739 T483 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-483]: qtp1415138589-483 startFullFlush
[junit4] 2> 204740 T483 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-483]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204740 T483 C77 oasu.LoggingInfoStream.message [DWFC][qtp1415138589-483]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_2, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 8 ]]
[junit4] 2> 204741 T483 C77 oasu.LoggingInfoStream.message [DWPT][qtp1415138589-483]: flush postings as segment _2 numDocs=1
[junit4] 2> 204743 T483 C77 oasu.LoggingInfoStream.message [DWPT][qtp1415138589-483]: new segment has 0 deleted docs
[junit4] 2> 204744 T483 C77 oasu.LoggingInfoStream.message [DWPT][qtp1415138589-483]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 204744 T483 C77 oasu.LoggingInfoStream.message [DWPT][qtp1415138589-483]: 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> 204745 T483 C77 oasu.LoggingInfoStream.message [DWPT][qtp1415138589-483]: flushed codec=Lucene42
[junit4] 2> 204745 T483 C77 oasu.LoggingInfoStream.message [DWPT][qtp1415138589-483]: flushed: segment=_2 ramUsed=0.079 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=1,083.24
[junit4] 2> 204746 T483 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-483]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 204746 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: publishFlushedSegment
[junit4] 2> 204747 T483 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-483]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=16 packetCount=1 totBytesUsed=1024
[junit4] 2> 204747 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: publish sets newSegment delGen=17 seg=_2(4.5):C1
[junit4] 2> 204747 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: now checkpoint "_2(4.5):C1" [1 segments ; isCommit = false]
[junit4] 2> 204748 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: 0 msec to checkpoint
[junit4] 2> 204748 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: apply all deletes during flush
[junit4] 2> 204749 T483 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-483]: applyDeletes: infos=[_2(4.5):C1] packetCount=1
[junit4] 2> 204749 T483 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-483]: applyDeletes took 0 msec
[junit4] 2> 204749 T483 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-483]: prune sis=org.apache.lucene.index.SegmentInfos@207f7d58 minGen=18 packetCount=1
[junit4] 2> 204750 T483 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-483]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 204750 T483 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-483]: qtp1415138589-483 finishFullFlush success=true
[junit4] 2> 204751 T483 C77 oasu.LoggingInfoStream.message [TMP][qtp1415138589-483]: findMerges: 1 segments
[junit4] 2> 204751 T483 C77 oasu.LoggingInfoStream.message [TMP][qtp1415138589-483]: seg=_2(4.5):C1 size=0.001 MB [floored]
[junit4] 2> 204752 T483 C77 oasu.LoggingInfoStream.message [TMP][qtp1415138589-483]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 204753 T483 C77 oasu.LoggingInfoStream.message [CMS][qtp1415138589-483]: now merge
[junit4] 2> 204753 T483 C77 oasu.LoggingInfoStream.message [CMS][qtp1415138589-483]: index: _2(4.5):C1
[junit4] 2> 204754 T483 C77 oasu.LoggingInfoStream.message [CMS][qtp1415138589-483]: no more merges pending; now return
[junit4] 2> 204755 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: startCommit(): start
[junit4] 2> 204758 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: startCommit index=_2(4.5):C1 changeCount=14
[junit4] 2> 204760 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: 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> 204760 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: commit: pendingCommit != null
[junit4] 2> 204761 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: commit: wrote segments file "segments_5"
[junit4] 2> 204761 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: now checkpoint "_2(4.5):C1" [1 segments ; isCommit = true]
[junit4] 2> 204762 T483 C77 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6cb2b9ec lockFactory=org.apache.lucene.store.NativeFSLockFactory@72402ecb),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6cb2b9ec lockFactory=org.apache.lucene.store.NativeFSLockFactory@72402ecb),segFN=segments_5,generation=5}
[junit4] 2> 204762 T483 C77 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 204763 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: deleteCommits: now decRef commit "segments_4"
[junit4] 2> 204763 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete "_1.fdx"
[junit4] 2> 204764 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete "_1_Lucene41_0.pos"
[junit4] 2> 204764 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: 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> 204765 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete "_1.nvm"
[junit4] 2> 204765 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete "_1_Lucene41_0.doc"
[junit4] 2> 204766 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: 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> 204766 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete "_1.fdt"
[junit4] 2> 204767 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: unable to remove file "_1.fdt": java.io.IOException: MockDirectoryWrapper: file "_1.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 204767 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete "_1.si"
[junit4] 2> 204768 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete "_1_Lucene41_0.tim"
[junit4] 2> 204768 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: 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> 204769 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete "_1.nvd"
[junit4] 2> 204769 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: unable to remove file "_1.nvd": java.io.IOException: MockDirectoryWrapper: file "_1.nvd" is still open: cannot delete; Will re-try later.
[junit4] 2> 204769 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete "_1_Lucene41_0.tip"
[junit4] 2> 204770 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete "_1.fnm"
[junit4] 2> 204770 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete "segments_4"
[junit4] 2> 204771 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: 9 msec to checkpoint
[junit4] 2> 204771 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: commit: done
[junit4] 2> 204772 T483 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-483]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204772 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 204772 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: flush at getReader
[junit4] 2> 204773 T483 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-483]: qtp1415138589-483 startFullFlush
[junit4] 2> 204773 T483 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-483]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204774 T483 C77 oasu.LoggingInfoStream.message [DWFC][qtp1415138589-483]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 9 ]]
[junit4] 2> 204775 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: apply all deletes during flush
[junit4] 2> 204775 T483 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-483]: applyDeletes: no deletes; skipping
[junit4] 2> 204776 T483 C77 oasu.LoggingInfoStream.message [BD][qtp1415138589-483]: prune sis=org.apache.lucene.index.SegmentInfos@207f7d58 minGen=18 packetCount=0
[junit4] 2> 204777 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: return reader version=11 reader=StandardDirectoryReader(segments_5:11:nrt _2(4.5):C1)
[junit4] 2> 204778 T483 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-483]: qtp1415138589-483 finishFullFlush success=true
[junit4] 2> 204778 T483 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-483]: getReader took 6 msec
[junit4] 2> 204779 T483 C77 oass.SolrIndexSearcher.<init> Opening Searcher@48719726 main
[junit4] 2> 204779 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete pending file _1_Lucene41_0.pos
[junit4] 2> 204780 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete "_1_Lucene41_0.pos"
[junit4] 2> 204780 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: 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> 204780 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete pending file _1_Lucene41_0.doc
[junit4] 2> 204781 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete "_1_Lucene41_0.doc"
[junit4] 2> 204782 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: 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> 204782 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete pending file _1.fdt
[junit4] 2> 204782 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete "_1.fdt"
[junit4] 2> 204783 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: unable to remove file "_1.fdt": java.io.IOException: MockDirectoryWrapper: file "_1.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 204783 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete pending file _1_Lucene41_0.tim
[junit4] 2> 204784 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete "_1_Lucene41_0.tim"
[junit4] 2> 204784 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: 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> 204784 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete pending file _1.nvd
[junit4] 2> 204785 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: delete "_1.nvd"
[junit4] 2> 204786 T483 C77 oasu.LoggingInfoStream.message [IFD][qtp1415138589-483]: unable to remove file "_1.nvd": java.io.IOException: MockDirectoryWrapper: file "_1.nvd" is still open: cannot delete; Will re-try later.
[junit4] 2> 204786 T483 C77 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 204786 T485 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@48719726 main{StandardDirectoryReader(segments_5:11:nrt _2(4.5):C1)}
[junit4] 2> 204792 T485 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 204795 T485 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@48719726 main{StandardDirectoryReader(segments_5:11:nrt _2(4.5):C1)}
[junit4] 2> 204796 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete pending file _1_Lucene41_0.pos
[junit4] 2> 204797 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete "_1_Lucene41_0.pos"
[junit4] 2> 204797 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete pending file _1_Lucene41_0.doc
[junit4] 2> 204797 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete "_1_Lucene41_0.doc"
[junit4] 2> 204798 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete pending file _1.fdt
[junit4] 2> 204798 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete "_1.fdt"
[junit4] 2> 204798 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete pending file _1_Lucene41_0.tim
[junit4] 2> 204799 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete "_1_Lucene41_0.tim"
[junit4] 2> 204799 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete pending file _1.nvd
[junit4] 2> 204799 T485 oasu.LoggingInfoStream.message [IFD][searcherExecutor-246-thread-1]: delete "_1.nvd"
[junit4] 2> 204800 T483 C77 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 65
[junit4] 2> 204812 T479 C77 oasc.SolrCore.execute [collection1] webapp=/solr path=/get params={id=DOCID&fl=id,name,aaa:[value+v%3Daaa]&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4] 2> 204822 T480 C77 oasc.SolrCore.execute [collection1] webapp=/solr path=/get params={id=DOCID&fl=id,name,aaa:[value+v%3Daaa]&wt=xml&qt=/get&version=2.2} status=0 QTime=0
[junit4] 2> 204827 T474 oas.SolrTestCaseJ4.tearDown ###Ending testRealtimeGet
[junit4] 2> 204839 T474 oas.SolrTestCaseJ4.setUp ###Starting testChineseDefaults
[junit4] 2> 204849 T481 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-481]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204850 T481 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-481]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 204850 T481 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-481]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204851 T481 C77 oasu.LoggingInfoStream.message [IW][qtp1415138589-481]: flush at getReader
[junit4] 2> 204851 T481 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-481]: qtp1415138589-481 startFullFlush
[junit4] 2> 204852 T481 C77 oasu.LoggingInfoStream.message [DW][qtp1415138589-481]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 204852 T481 C77 oasu.LoggingInfoStream.message [DWFC][qtp1415138589-481]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 10 ]]
[junit
[...truncated too long message...]
rectUpdateHandler2{commits=55,autocommit maxTime=15000ms,autocommits=1,soft autocommits=3,optimizes=2,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=1,cumulative_adds=128,cumulative_deletesById=1,cumulative_deletesByQuery=26,cumulative_errors=1}
[junit4] 2> 415249 T474 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 415250 T474 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 415250 T474 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 415263 T474 C78 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: now flush at close waitForMerges=true
[junit4] 2> 415264 T474 C78 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: start flush: applyAllDeletes=true
[junit4] 2> 415264 T474 C78 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: index before flush _12(4.5):C10
[junit4] 2> 415265 T474 C78 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker startFullFlush
[junit4] 2> 415269 T474 C78 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 415271 T474 C78 oasu.LoggingInfoStream.message [DWFC][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 119 ]]
[junit4] 2> 415272 T474 C78 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker finishFullFlush success=true
[junit4] 2> 415272 T474 C78 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: apply all deletes during flush
[junit4] 2> 415273 T474 C78 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: applyDeletes: no deletes; skipping
[junit4] 2> 415273 T474 C78 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@207f7d58 minGen=219 packetCount=0
[junit4] 2> 415274 T474 C78 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: now merge
[junit4] 2> 415274 T474 C78 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: index: _12(4.5):C10
[junit4] 2> 415275 T474 C78 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: no more merges pending; now return
[junit4] 2> 415275 T474 C78 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: waitForMerges
[junit4] 2> 415276 T474 C78 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: waitForMerges done
[junit4] 2> 415276 T474 C78 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: now call final commit()
[junit4] 2> 415277 T474 C78 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: commit: start
[junit4] 2> 415277 T474 C78 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: commit: enter lock
[junit4] 2> 415277 T474 C78 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: commit: now prepare
[junit4] 2> 415278 T474 C78 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: prepareCommit: flush
[junit4] 2> 415278 T474 C78 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: index before flush _12(4.5):C10
[junit4] 2> 415279 T474 C78 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker startFullFlush
[junit4] 2> 415281 T474 C78 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 415282 T474 C78 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: apply all deletes during flush
[junit4] 2> 415282 T474 C78 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: applyDeletes: no deletes; skipping
[junit4] 2> 415283 T474 C78 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@207f7d58 minGen=219 packetCount=0
[junit4] 2> 415283 T474 C78 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker finishFullFlush success=true
[junit4] 2> 415284 T474 C78 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: startCommit(): start
[junit4] 2> 415284 T474 C78 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: skip startCommit(): no changes pending
[junit4] 2> 415285 T474 C78 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: commit: pendingCommit == null; skip
[junit4] 2> 415285 T474 C78 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: commit: done
[junit4] 2> 415286 T474 C78 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[F2078D00D4BA7149]-worker]: at close: _12(4.5):C10
[junit4] 2> 415288 T474 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 415289 T474 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 415289 T474 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleJettyTest-1376249694218/index [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleJettyTest-1376249694218/index;done=false>>]
[junit4] 2> 415290 T474 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleJettyTest-1376249694218/index
[junit4] 2> 415290 T474 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleJettyTest-1376249694218 [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleJettyTest-1376249694218;done=false>>]
[junit4] 2> 415291 T474 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleJettyTest-1376249694218
[junit4] 2> 415291 T474 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 415347 T474 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene42: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=es_AR, timezone=US/Pacific
[junit4] 2> NOTE: Mac OS X 10.8.4 x86_64/Apple Inc. 1.6.0_51 (64-bit)/cpus=2,threads=1,free=64900776,total=219414528
[junit4] 2> NOTE: All tests run in this JVM: [TestBatchUpdate, MergeIndexesEmbeddedTest, FacetFieldTest, AnlysisResponseBaseTest, ClientUtilsTest, ModifiableSolrParamsTest, TestLBHttpSolrServer, JettyWebappTest, LargeVolumeJettyTest, FieldAnalysisResponseTest, SolrExampleStreamingTest, CloudSolrServerTest, SolrExceptionTest, SolrExampleBinaryTest, BasicHttpSolrServerTest, TestJavaBinCodec, SolrDocumentTest, TestCoreAdmin, TestHash, LargeVolumeEmbeddedTest, SolrExampleJettyTest]
[junit4] Completed in 213.24s, 27 tests, 1 error <<< FAILURES!
[...truncated 81 lines...]
BUILD FAILED
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:395: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:375: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:194: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:449: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1233: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:876: There were test failures: 46 suites, 272 tests, 1 error
Total time: 116 minutes 41 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.6.0 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure