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/05 07:15:42 UTC
[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 688 -
Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/688/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseG1GC
1 tests failed.
REGRESSION: org.apache.solr.client.solrj.embedded.SolrExampleStreamingBinaryTest.testPivotFacets
Error Message:
IOException occured when talking to server at: https://127.0.0.1:53768/solr/collection1
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:53768/solr/collection1
at __randomizedtesting.SeedInfo.seed([619FEC580107CFFD:DF590C93D52056B3]: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.impl.ConcurrentUpdateSolrServer.request(ConcurrentUpdateSolrServer.java:256)
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.doPivotFacetTest(SolrExampleTests.java:1002)
at org.apache.solr.client.solrj.SolrExampleTests.testPivotFacets(SolrExampleTests.java:990)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Caused by: org.apache.http.NoHttpResponseException: The target server failed to respond
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:95)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:62)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:254)
at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:289)
at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:252)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:191)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:717)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:522)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
... 47 more
Build Log:
[...truncated 10801 lines...]
[junit4] Suite: org.apache.solr.client.solrj.embedded.SolrExampleStreamingBinaryTest
[junit4] 2> 66035 T97 oas.SolrTestCaseJ4.startTrackingSearchers WARN startTrackingSearchers: numOpens=7 numCloses=7
[junit4] 2> 66036 T97 oas.SolrJettyTestBase.beforeSolrJettyTestBase Randomized ssl (true) and clientAuth (false)
[junit4] 2> 66037 T97 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-SolrExampleStreamingBinaryTest-1375679224393
[junit4] 2> 66039 T97 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 66095 T97 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 66732 T97 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 66750 T97 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:53768
[junit4] 2> 66753 T97 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 66776 T97 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 66777 T97 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr
[junit4] 2> 66778 T97 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/'
[junit4] 2> 66907 T97 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/solr.xml
[junit4] 2> 67188 T97 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 67189 T97 oasc.CoreContainer.<init> New CoreContainer 1003797945
[junit4] 2> 67190 T97 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/]
[junit4] 2> 67195 T97 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 67197 T97 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 67197 T97 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 67198 T97 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 67199 T97 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 67200 T97 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 67201 T97 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 67202 T97 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 67203 T97 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 67204 T97 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 67223 T97 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr
[junit4] 2> 67266 T97 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/
[junit4] 2> 67279 T97 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 67288 T107 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1
[junit4] 2> 67289 T107 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/'
[junit4] 2> 67478 T107 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 67479 T107 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> 67480 T107 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> 67481 T107 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> 67481 T107 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> 67482 T107 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> 67483 T107 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> 67484 T107 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> 67484 T107 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> 67579 T107 oasu.SolrIndexConfig.<init> IndexWriter infoStream solr logging is enabled
[junit4] 2> 67648 T107 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 67814 T107 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 67815 T107 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 67937 T107 oass.IndexSchema.readSchema [collection1] Schema name=example
[junit4] 2> 69816 T107 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 69903 T107 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 69920 T107 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 70210 T107 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 70211 T107 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-SolrExampleStreamingBinaryTest-1375679224393/
[junit4] 2> 70212 T107 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6a628568
[junit4] 2> 70248 T107 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4] 2> 70249 T107 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
[junit4] 2> 70250 T107 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleStreamingBinaryTest-1375679224393
[junit4] 2> 70251 T107 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-SolrExampleStreamingBinaryTest-1375679224393/index/
[junit4] 2> 70251 T107 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-SolrExampleStreamingBinaryTest-1375679224393/index' doesn't exist. Creating new index...
[junit4] 2> 70252 T107 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleStreamingBinaryTest-1375679224393/index
[junit4] 2> 70255 T107 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-92-thread-1]: init: current segments file is "null"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@76fe1a35
[junit4] 2> 70255 T107 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-92-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 70256 T107 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-92-thread-1]: 0 msec to checkpoint
[junit4] 2> 70256 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: init: create=true
[junit4] 2> 70257 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]:
[junit4] 2> dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@538330b2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d4419bd)
[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@246aca9b
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2>
[junit4] 2> 70257 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: now flush at close waitForMerges=true
[junit4] 2> 70258 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: start flush: applyAllDeletes=true
[junit4] 2> 70258 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: index before flush
[junit4] 2> 70259 T107 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-92-thread-1]: coreLoadExecutor-92-thread-1 startFullFlush
[junit4] 2> 70259 T107 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-92-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 70260 T107 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-92-thread-1]: coreLoadExecutor-92-thread-1 finishFullFlush success=true
[junit4] 2> 70260 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: apply all deletes during flush
[junit4] 2> 70261 T107 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-92-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@5f1b98ca minGen=9223372036854775807 packetCount=0
[junit4] 2> 70261 T107 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-92-thread-1]: now merge
[junit4] 2> 70263 T107 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-92-thread-1]: index:
[junit4] 2> 70265 T107 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-92-thread-1]: no more merges pending; now return
[junit4] 2> 70266 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: waitForMerges
[junit4] 2> 70266 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: waitForMerges done
[junit4] 2> 70267 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: now call final commit()
[junit4] 2> 70267 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: commit: start
[junit4] 2> 70268 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: commit: enter lock
[junit4] 2> 70268 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: commit: now prepare
[junit4] 2> 70269 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: prepareCommit: flush
[junit4] 2> 70269 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: index before flush
[junit4] 2> 70270 T107 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-92-thread-1]: coreLoadExecutor-92-thread-1 startFullFlush
[junit4] 2> 70271 T107 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-92-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 70271 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: apply all deletes during flush
[junit4] 2> 70272 T107 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-92-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@5f1b98ca minGen=9223372036854775807 packetCount=0
[junit4] 2> 70273 T107 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-92-thread-1]: coreLoadExecutor-92-thread-1 finishFullFlush success=true
[junit4] 2> 70273 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: startCommit(): start
[junit4] 2> 70274 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: startCommit index= changeCount=1
[junit4] 2> 70276 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: done all syncs: []
[junit4] 2> 70276 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: commit: pendingCommit != null
[junit4] 2> 70277 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: commit: wrote segments file "segments_1"
[junit4] 2> 70278 T107 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-92-thread-1]: now checkpoint "" [0 segments ; isCommit = true]
[junit4] 2> 70278 T107 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@538330b2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d4419bd),segFN=segments_1,generation=1}
[junit4] 2> 70279 T107 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 70280 T107 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-92-thread-1]: 2 msec to checkpoint
[junit4] 2> 70281 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: commit: done
[junit4] 2> 70281 T107 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-92-thread-1]: at close:
[junit4] 2> 70284 T107 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 70285 T107 oasc.SolrCore.initWriters adding lazy queryResponseWriter: solr.VelocityResponseWriter
[junit4] 2> 70286 T107 oasc.SolrCore.initWriters created velocity: solr.VelocityResponseWriter
[junit4] 2> 70286 T107 oasc.SolrCore.initWriters created xslt: solr.XSLTResponseWriter
[junit4] 2> 70287 T107 oasr.XSLTResponseWriter.init xsltCacheLifetimeSeconds=5
[junit4] 2> 70318 T107 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 70320 T107 oasc.RequestHandlers.initHandlersFromConfig created /query: solr.SearchHandler
[junit4] 2> 70322 T107 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 70323 T107 oasc.RequestHandlers.initHandlersFromConfig created /browse: solr.SearchHandler
[junit4] 2> 70325 T107 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 70327 T107 oasc.RequestHandlers.initHandlersFromConfig created /update/json: solr.JsonUpdateRequestHandler
[junit4] 2> 70328 T107 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: solr.CSVRequestHandler
[junit4] 2> 70329 T107 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
[junit4] 2> 70330 T107 oasc.RequestHandlers.initHandlersFromConfig created /update/extract: solr.extraction.ExtractingRequestHandler
[junit4] 2> 70330 T107 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.FieldAnalysisRequestHandler
[junit4] 2> 70331 T107 oasc.RequestHandlers.initHandlersFromConfig created /analysis/field: solr.FieldAnalysisRequestHandler
[junit4] 2> 70331 T107 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
[junit4] 2> 70332 T107 oasc.RequestHandlers.initHandlersFromConfig created /analysis/document: solr.DocumentAnalysisRequestHandler
[junit4] 2> 70333 T107 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 70334 T107 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
[junit4] 2> 70341 T107 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 70343 T107 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 70344 T107 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 70344 T107 oasc.RequestHandlers.initHandlersFromConfig created /spell: solr.SearchHandler
[junit4] 2> 70345 T107 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 70345 T107 oasc.RequestHandlers.initHandlersFromConfig created /tvrh: solr.SearchHandler
[junit4] 2> 70346 T107 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 70346 T107 oasc.RequestHandlers.initHandlersFromConfig created /terms: solr.SearchHandler
[junit4] 2> 70347 T107 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 70354 T107 oasc.RequestHandlers.initHandlersFromConfig created /elevate: solr.SearchHandler
[junit4] 2> 70377 T107 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 70380 T107 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 70383 T107 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 70430 T107 oass.SolrIndexSearcher.<init> Opening Searcher@4c885344 main
[junit4] 2> 70433 T107 oasu.CommitTracker.<init> Hard AutoCommit: if uncommited for 15000ms;
[junit4] 2> 70434 T107 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 70437 T107 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 70438 T107 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> 70439 T107 oashc.SpellCheckComponent.inform No queryConverter defined, using default converter
[junit4] 2> 70442 T107 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> 70512 T107 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 70527 T108 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@4c885344 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> ASYNC NEW_CORE C14 name=collection1 org.apache.solr.core.SolrCore@3f3c92ad
[junit4] 2> 70531 T108 C14 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=4
[junit4] 2> 70532 T108 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 70534 T108 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
[junit4] 2> 70538 T108 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
[junit4] 2> 70545 T108 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4c885344 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 70558 T107 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 70560 T97 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0
[junit4] 2> 70561 T97 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 70562 T97 oas.SolrJettyTestBase.createJetty Jetty Assigned Port#53768
[junit4] 2> 70579 T97 oas.SolrTestCaseJ4.setUp ###Starting testChineseDefaults
[junit4] 2> 70586 T97 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 71005 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: init: current segments file is "segments_1"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@76fe1a35
[junit4] 2> 71006 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: init: load commit "segments_1"
[junit4] 2> 71007 T102 C14 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@538330b2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d4419bd),segFN=segments_1,generation=1}
[junit4] 2> 71008 T102 C14 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 71008 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 71009 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: 0 msec to checkpoint
[junit4] 2> 71009 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: init: create=false
[junit4] 2> 71010 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]:
[junit4] 2> dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@538330b2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d4419bd)
[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@3f10d98a
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2>
[junit4] 2> 71012 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: flush at getReader
[junit4] 2> 71013 T102 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-102]: qtp1845849350-102 startFullFlush
[junit4] 2> 71014 T102 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-102]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71016 T102 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-102]: qtp1845849350-102: flush naked frozen global deletes
[junit4] 2> 71016 T102 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-102]: push deletes 1 deleted queries bytesUsed=32 delGen=1 packetCount=1 totBytesUsed=32
[junit4] 2> 71017 T102 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-102]: flush: push buffered deletes: 1 deleted queries bytesUsed=32
[junit4] 2> 71018 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: apply all deletes during flush
[junit4] 2> 71018 T102 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-102]: prune sis=org.apache.lucene.index.SegmentInfos@5d7487fb minGen=9223372036854775807 packetCount=1
[junit4] 2> 71019 T102 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-102]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 71019 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
[junit4] 2> 71020 T102 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-102]: qtp1845849350-102 finishFullFlush success=true
[junit4] 2> 71020 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: getReader took 8 msec
[junit4] 2> 71021 T102 C14 oass.SolrIndexSearcher.<init> Opening Searcher@499fdc26 realtime
[junit4] 2> 71023 T102 C14 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1442504223601197056)} 0 32
[junit4] 2> 71034 T103 C14 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 71035 T103 C14 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 71036 T103 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-103]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71036 T103 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-103]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
[junit4] 2> 71037 T103 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-103]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71037 T103 C14 oass.SolrIndexSearcher.<init> Opening Searcher@c56e087 main
[junit4] 2> 71038 T103 C14 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 71039 T108 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@c56e087 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 71040 T108 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 71049 T108 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c56e087 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 71051 T103 C14 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 18
[junit4] 2> 71061 T104 C14 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 71064 T97 oascsi.ConcurrentUpdateSolrServer.request blocking for commit/optimize
[junit4] 2> 71073 T105 C14 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 71076 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: commit: start
[junit4] 2> 71080 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: commit: enter lock
[junit4] 2> 71082 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: commit: now prepare
[junit4] 2> 71083 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: prepareCommit: flush
[junit4] 2> 71083 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: index before flush
[junit4] 2> 71084 T105 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-105]: qtp1845849350-105 startFullFlush
[junit4] 2> 71085 T105 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-105]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71086 T105 C14 oasu.LoggingInfoStream.message [DWFC][qtp1845849350-105]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_0, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 1 ]]
[junit4] 2> 71087 T105 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-105]: flush postings as segment _0 numDocs=1
[junit4] 2> 71091 T105 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-105]: new segment has 0 deleted docs
[junit4] 2> 71091 T105 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-105]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 71092 T105 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-105]: flushedFiles=[_0.fnm, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0.nvd, _0.fdx, _0.nvm, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0.fdt]
[junit4] 2> 71092 T105 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-105]: flushed codec=Lucene42
[junit4] 2> 71093 T105 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-105]: flushed: segment=_0 ramUsed=0.071 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=1,230.723
[junit4] 2> 71094 T105 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-105]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 71095 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: publishFlushedSegment
[junit4] 2> 71096 T105 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-105]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=3 packetCount=1 totBytesUsed=1024
[junit4] 2> 71097 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: publish sets newSegment delGen=4 seg=_0(4.5):C1
[junit4] 2> 71097 T105 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-105]: now checkpoint "_0(4.5):C1" [1 segments ; isCommit = false]
[junit4] 2> 71098 T105 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-105]: 0 msec to checkpoint
[junit4] 2> 71098 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: apply all deletes during flush
[junit4] 2> 71101 T105 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-105]: applyDeletes: infos=[_0(4.5):C1] packetCount=1
[junit4] 2> 71101 T105 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-105]: applyDeletes took 0 msec
[junit4] 2> 71102 T105 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-105]: prune sis=org.apache.lucene.index.SegmentInfos@5d7487fb minGen=5 packetCount=1
[junit4] 2> 71103 T105 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-105]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 71103 T105 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-105]: qtp1845849350-105 finishFullFlush success=true
[junit4] 2> 71104 T105 C14 oasu.LoggingInfoStream.message [TMP][qtp1845849350-105]: findMerges: 1 segments
[junit4] 2> 71105 T105 C14 oasu.LoggingInfoStream.message [TMP][qtp1845849350-105]: seg=_0(4.5):C1 size=0.001 MB [floored]
[junit4] 2> 71105 T105 C14 oasu.LoggingInfoStream.message [TMP][qtp1845849350-105]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 71106 T105 C14 oasu.LoggingInfoStream.message [CMS][qtp1845849350-105]: now merge
[junit4] 2> 71106 T105 C14 oasu.LoggingInfoStream.message [CMS][qtp1845849350-105]: index: _0(4.5):C1
[junit4] 2> 71107 T105 C14 oasu.LoggingInfoStream.message [CMS][qtp1845849350-105]: no more merges pending; now return
[junit4] 2> 71107 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: startCommit(): start
[junit4] 2> 71108 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: startCommit index=_0(4.5):C1 changeCount=3
[junit4] 2> 71109 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: done all syncs: [_0.fnm, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0.nvd, _0.fdx, _0.si, _0.nvm, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip]
[junit4] 2> 71109 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: commit: pendingCommit != null
[junit4] 2> 71110 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: commit: wrote segments file "segments_2"
[junit4] 2> 71110 T105 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-105]: now checkpoint "_0(4.5):C1" [1 segments ; isCommit = true]
[junit4] 2> 71111 T105 C14 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@538330b2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d4419bd),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@538330b2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d4419bd),segFN=segments_2,generation=2}
[junit4] 2> 71112 T105 C14 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 71112 T105 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-105]: deleteCommits: now decRef commit "segments_1"
[junit4] 2> 71113 T105 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-105]: delete "segments_1"
[junit4] 2> 71113 T105 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-105]: 2 msec to checkpoint
[junit4] 2> 71114 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: commit: done
[junit4] 2> 71114 T105 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-105]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71115 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 71116 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: flush at getReader
[junit4] 2> 71116 T105 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-105]: qtp1845849350-105 startFullFlush
[junit4] 2> 71117 T105 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-105]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71117 T105 C14 oasu.LoggingInfoStream.message [DWFC][qtp1845849350-105]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 2 ]]
[junit4] 2> 71118 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: apply all deletes during flush
[junit4] 2> 71118 T105 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-105]: applyDeletes: no deletes; skipping
[junit4] 2> 71119 T105 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-105]: prune sis=org.apache.lucene.index.SegmentInfos@5d7487fb minGen=5 packetCount=0
[junit4] 2> 71121 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: return reader version=3 reader=StandardDirectoryReader(segments_2:3:nrt _0(4.5):C1)
[junit4] 2> 71122 T105 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-105]: qtp1845849350-105 finishFullFlush success=true
[junit4] 2> 71127 T105 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-105]: getReader took 11 msec
[junit4] 2> 71128 T105 C14 oass.SolrIndexSearcher.<init> Opening Searcher@277ee847 main
[junit4] 2> 71129 T105 C14 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 71129 T108 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@277ee847 main{StandardDirectoryReader(segments_2:3:nrt _0(4.5):C1)}
[junit4] 2> 71130 T108 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 71141 T108 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@277ee847 main{StandardDirectoryReader(segments_2:3:nrt _0(4.5):C1)}
[junit4] 2> 71146 T105 C14 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {add=[42 (1442504223673548800)],commit=} 0 77
[junit4] 2> 71165 T106 C14 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=????&wt=javabin&version=2} hits=1 status=0 QTime=3
[junit4] 2> 71169 T97 oas.SolrTestCaseJ4.tearDown ###Ending testChineseDefaults
[junit4] 2> 71189 T97 oas.SolrTestCaseJ4.setUp ###Starting testUnicode
[junit4] 2> 71196 T100 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-100]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71197 T100 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-100]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 71197 T100 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-100]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71198 T100 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-100]: flush at getReader
[junit4] 2> 71198 T100 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-100]: qtp1845849350-100 startFullFlush
[junit4] 2> 71199 T100 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-100]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71202 T100 C14 oasu.LoggingInfoStream.message [DWFC][qtp1845849350-100]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 3 ]]
[junit4] 2> 71209 T100 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-100]: qtp1845849350-100: flush naked frozen global deletes
[junit4] 2> 71210 T100 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-100]: push deletes 1 deleted queries bytesUsed=32 delGen=7 packetCount=1 totBytesUsed=32
[junit4] 2> 71211 T100 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-100]: flush: push buffered deletes: 1 deleted queries bytesUsed=32
[junit4] 2> 71211 T100 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-100]: apply all deletes during flush
[junit4] 2> 71212 T100 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-100]: applyDeletes: infos=[_0(4.5):C1] packetCount=1
[junit4] 2> 71213 T100 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-100]: seg=_0(4.5):C1 segGen=5 coalesced deletes=[CoalescedDeletes(termSets=1,queries=1)] newDelCount=1 100% deleted
[junit4] 2> 71214 T100 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-100]: applyDeletes took 2 msec
[junit4] 2> 71215 T100 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-100]: now checkpoint "_0(4.5):C1/1" [1 segments ; isCommit = false]
[junit4] 2> 71215 T100 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-100]: 0 msec to checkpoint
[junit4] 2> 71216 T100 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-100]: drop 100% deleted segments: _0(4.5):C1/1
[junit4] 2> 71216 T100 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-100]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 71217 T100 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-100]: 0 msec to checkpoint
[junit4] 2> 71217 T100 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-100]: prune sis=org.apache.lucene.index.SegmentInfos@5d7487fb minGen=9223372036854775807 packetCount=1
[junit4] 2> 71218 T100 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-100]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 71219 T100 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-100]: return reader version=5 reader=StandardDirectoryReader(segments_2:5:nrt)
[junit4] 2> 71219 T100 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-100]: qtp1845849350-100 finishFullFlush success=true
[junit4] 2> 71220 T100 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-100]: getReader took 22 msec
[junit4] 2> 71220 T100 C14 oass.SolrIndexSearcher.<init> Opening Searcher@1a00a506 realtime
[junit4] 2> 71221 T100 C14 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1442504223803572224)} 0 27
[junit4] 2> 71252 T111 oascsi.ConcurrentUpdateSolrServer$Runner.run starting runner: org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer$Runner@1f36154e
[junit4] 2> 71539 T102 C14 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[0 (1442504223893749760), 1 (1442504223895846912), 2 (1442504223895846913), 3 (1442504223896895488), 4 (1442504223897944064)]} 0 259
[junit4] 2> 71542 T111 oascsi.ConcurrentUpdateSolrServer$Runner.run Status for: 0 is 200
[junit4] 2> 71544 T111 oascsi.ConcurrentUpdateSolrServer$Runner.run finished: org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer$Runner@1f36154e
[junit4] 2> 71549 T104 C14 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 71549 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: commit: start
[junit4] 2> 71550 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: commit: enter lock
[junit4] 2> 71550 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: commit: now prepare
[junit4] 2> 71551 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: prepareCommit: flush
[junit4] 2> 71552 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: index before flush
[junit4] 2> 71553 T104 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-104]: qtp1845849350-104 startFullFlush
[junit4] 2> 71554 T104 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-104]: anyChanges? numDocsInRam=5 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71554 T104 C14 oasu.LoggingInfoStream.message [DWFC][qtp1845849350-104]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 4 deleted terms (unique count=4) bytesUsed=660, segment=_1, aborting=false, numDocsInRAM=5, deleteQueue=DWDQ: [ generation: 4 ]]
[junit4] 2> 71557 T104 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-104]: flush postings as segment _1 numDocs=5
[junit4] 2> 71564 T104 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-104]: new segment has 0 deleted docs
[junit4] 2> 71565 T104 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-104]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 71566 T104 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-104]: flushedFiles=[_1.fdx, _1_Lucene41_0.doc, _1.fdt, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _1.fnm]
[junit4] 2> 71567 T104 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-104]: flushed codec=Lucene42
[junit4] 2> 71568 T104 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-104]: flushed: segment=_1 ramUsed=0.064 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=4,283.399
[junit4] 2> 71569 T104 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-104]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 71570 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: publishFlushedSegment
[junit4] 2> 71571 T104 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-104]: push deletes 5 deleted terms (unique count=5) bytesUsed=1024 delGen=9 packetCount=1 totBytesUsed=1024
[junit4] 2> 71572 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: publish sets newSegment delGen=10 seg=_1(4.5):C5
[junit4] 2> 71572 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: now checkpoint "_1(4.5):C5" [1 segments ; isCommit = false]
[junit4] 2> 71572 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: 0 msec to checkpoint
[junit4] 2> 71573 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: apply all deletes during flush
[junit4] 2> 71573 T104 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-104]: applyDeletes: infos=[_1(4.5):C5] packetCount=1
[junit4] 2> 71573 T104 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-104]: applyDeletes took 0 msec
[junit4] 2> 71574 T104 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-104]: prune sis=org.apache.lucene.index.SegmentInfos@5d7487fb minGen=11 packetCount=1
[junit4] 2> 71574 T104 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-104]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 71574 T104 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-104]: qtp1845849350-104 finishFullFlush success=true
[junit4] 2> 71575 T104 C14 oasu.LoggingInfoStream.message [TMP][qtp1845849350-104]: findMerges: 1 segments
[junit4] 2> 71575 T104 C14 oasu.LoggingInfoStream.message [TMP][qtp1845849350-104]: seg=_1(4.5):C5 size=0.001 MB [floored]
[junit4] 2> 71576 T104 C14 oasu.LoggingInfoStream.message [TMP][qtp1845849350-104]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 71576 T104 C14 oasu.LoggingInfoStream.message [CMS][qtp1845849350-104]: now merge
[junit4] 2> 71577 T104 C14 oasu.LoggingInfoStream.message [CMS][qtp1845849350-104]: index: _1(4.5):C5
[junit4] 2> 71577 T104 C14 oasu.LoggingInfoStream.message [CMS][qtp1845849350-104]: no more merges pending; now return
[junit4] 2> 71578 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: startCommit(): start
[junit4] 2> 71578 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: startCommit index=_1(4.5):C5 changeCount=8
[junit4] 2> 71579 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: done all syncs: [_1.fdx, _1_Lucene41_0.doc, _1.fdt, _1.si, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _1.fnm]
[junit4] 2> 71579 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: commit: pendingCommit != null
[junit4] 2> 71580 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: commit: wrote segments file "segments_3"
[junit4] 2> 71581 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: now checkpoint "_1(4.5):C5" [1 segments ; isCommit = true]
[junit4] 2> 71581 T104 C14 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@538330b2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d4419bd),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@538330b2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d4419bd),segFN=segments_3,generation=3}
[junit4] 2> 71582 T104 C14 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 71582 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: deleteCommits: now decRef commit "segments_2"
[junit4] 2> 71582 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete "_0.fnm"
[junit4] 2> 71583 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete "_0_Lucene41_0.doc"
[junit4] 2> 71583 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: 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> 71583 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete "_0_Lucene41_0.pos"
[junit4] 2> 71584 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: 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> 71584 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete "_0.nvd"
[junit4] 2> 71585 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: unable to remove file "_0.nvd": java.io.IOException: MockDirectoryWrapper: file "_0.nvd" is still open: cannot delete; Will re-try later.
[junit4] 2> 71585 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete "segments_2"
[junit4] 2> 71585 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete "_0.fdx"
[junit4] 2> 71586 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete "_0.si"
[junit4] 2> 71586 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete "_0.nvm"
[junit4] 2> 71587 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete "_0_Lucene41_0.tim"
[junit4] 2> 71587 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: 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> 71587 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete "_0.fdt"
[junit4] 2> 71588 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: unable to remove file "_0.fdt": java.io.IOException: MockDirectoryWrapper: file "_0.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 71588 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete "_0_Lucene41_0.tip"
[junit4] 2> 71588 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: 7 msec to checkpoint
[junit4] 2> 71589 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: commit: done
[junit4] 2> 71589 T104 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-104]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71589 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 71590 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: flush at getReader
[junit4] 2> 71590 T104 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-104]: qtp1845849350-104 startFullFlush
[junit4] 2> 71591 T104 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-104]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71591 T104 C14 oasu.LoggingInfoStream.message [DWFC][qtp1845849350-104]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 5 ]]
[junit4] 2> 71591 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: apply all deletes during flush
[junit4] 2> 71592 T104 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-104]: applyDeletes: no deletes; skipping
[junit4] 2> 71592 T104 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-104]: prune sis=org.apache.lucene.index.SegmentInfos@5d7487fb minGen=11 packetCount=0
[junit4] 2> 71593 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: return reader version=7 reader=StandardDirectoryReader(segments_3:7:nrt _1(4.5):C5)
[junit4] 2> 71594 T104 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-104]: qtp1845849350-104 finishFullFlush success=true
[junit4] 2> 71594 T104 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-104]: getReader took 4 msec
[junit4] 2> 71595 T104 C14 oass.SolrIndexSearcher.<init> Opening Searcher@462619c6 main
[junit4] 2> 71595 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete pending file _0_Lucene41_0.doc
[junit4] 2> 71595 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete "_0_Lucene41_0.doc"
[junit4] 2> 71596 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: 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> 71596 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete pending file _0_Lucene41_0.pos
[junit4] 2> 71597 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete "_0_Lucene41_0.pos"
[junit4] 2> 71597 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: 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> 71597 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete pending file _0.nvd
[junit4] 2> 71599 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete "_0.nvd"
[junit4] 2> 71599 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: unable to remove file "_0.nvd": java.io.IOException: MockDirectoryWrapper: file "_0.nvd" is still open: cannot delete; Will re-try later.
[junit4] 2> 71599 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete pending file _0_Lucene41_0.tim
[junit4] 2> 71600 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete "_0_Lucene41_0.tim"
[junit4] 2> 71600 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: 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> 71600 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete pending file _0.fdt
[junit4] 2> 71601 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: delete "_0.fdt"
[junit4] 2> 71601 T104 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-104]: unable to remove file "_0.fdt": java.io.IOException: MockDirectoryWrapper: file "_0.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 71602 T104 C14 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 71604 T108 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@462619c6 main{StandardDirectoryReader(segments_3:7:nrt _1(4.5):C5)}
[junit4] 2> 71607 T108 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 71617 T108 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@462619c6 main{StandardDirectoryReader(segments_3:7:nrt _1(4.5):C5)}
[junit4] 2> 71621 T108 oasu.LoggingInfoStream.message [IFD][searcherExecutor-93-thread-1]: delete pending file _0_Lucene41_0.doc
[junit4] 2> 71622 T108 oasu.LoggingInfoStream.message [IFD][searcherExecutor-93-thread-1]: delete "_0_Lucene41_0.doc"
[junit4] 2> 71622 T108 oasu.LoggingInfoStream.message [IFD][searcherExecutor-93-thread-1]: delete pending file _0_Lucene41_0.pos
[junit4] 2> 71622 T108 oasu.LoggingInfoStream.message [IFD][searcherExecutor-93-thread-1]: delete "_0_Lucene41_0.pos"
[junit4] 2> 71623 T108 oasu.LoggingInfoStream.message [IFD][searcherExecutor-93-thread-1]: delete pending file _0.nvd
[junit4] 2> 71623 T108 oasu.LoggingInfoStream.message [IFD][searcherExecutor-93-thread-1]: delete "_0.nvd"
[junit4] 2> 71623 T108 oasu.LoggingInfoStream.message [IFD][searcherExecutor-93-thread-1]: delete pending file _0_Lucene41_0.tim
[junit4] 2> 71624 T108 oasu.LoggingInfoStream.message [IFD][searcherExecutor-93-thread-1]: delete "_0_Lucene41_0.tim"
[junit4] 2> 71624 T108 oasu.LoggingInfoStream.message [IFD][searcherExecutor-93-thread-1]: delete pending file _0.fdt
[junit4] 2> 71625 T108 oasu.LoggingInfoStream.message [IFD][searcherExecutor-93-thread-1]: delete "_0.fdt"
[junit4] 2> 71625 T104 C14 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 77
[junit4] 2> 71634 T105 C14 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2&rows=5} hits=5 status=0 QTime=1
[junit4] 2> 71668 T106 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-106]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71673 T106 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-106]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 71675 T106 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-106]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71676 T106 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-106]: flush at getReader
[junit4] 2> 71676 T106 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-106]: qtp1845849350-106 startFullFlush
[junit4] 2> 71677 T106 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-106]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71677 T106 C14 oasu.LoggingInfoStream.message [DWFC][qtp1845849350-106]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 6 ]]
[junit4] 2> 71678 T106 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-106]: qtp1845849350-106: flush naked frozen global deletes
[junit4] 2> 71681 T106 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-106]: push deletes 1 deleted queries bytesUsed=32 delGen=13 packetCount=1 totBytesUsed=32
[junit4] 2> 71682 T106 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-106]: flush: push buffered deletes: 1 deleted queries bytesUsed=32
[junit4] 2> 71682 T106 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-106]: apply all deletes during flush
[junit4] 2> 71683 T106 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-106]: applyDeletes: infos=[_1(4.5):C5] packetCount=1
[junit4] 2> 71684 T106 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-106]: seg=_1(4.5):C5 segGen=11 coalesced deletes=[CoalescedDeletes(termSets=1,queries=1)] newDelCount=5 100% deleted
[junit4] 2> 71685 T106 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-106]: applyDeletes took 2 msec
[junit4] 2> 71686 T106 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-106]: now checkpoint "_1(4.5):C5/5" [1 segments ; isCommit = false]
[junit4] 2> 71687 T106 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-106]: 0 msec to checkpoint
[junit4] 2> 71687 T106 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-106]: drop 100% deleted segments: _1(4.5):C5/5
[junit4] 2> 71688 T106 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-106]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 71692 T106 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-106]: 4 msec to checkpoint
[junit4] 2> 71693 T106 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-106]: prune sis=org.apache.lucene.index.SegmentInfos@5d7487fb minGen=9223372036854775807 packetCount=1
[junit4] 2> 71693 T106 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-106]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 71694 T106 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-106]: return reader version=9 reader=StandardDirectoryReader(segments_3:9:nrt)
[junit4] 2> 71694 T106 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-106]: qtp1845849350-106 finishFullFlush success=true
[junit4] 2> 71694 T106 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-106]: getReader took 18 msec
[junit4] 2> 71695 T106 C14 oass.SolrIndexSearcher.<init> Opening Searcher@80b1d65 realtime
[junit4] 2> 71695 T106 C14 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1442504224298500096)} 0 30
[junit4] 2> 71700 T111 oascsi.ConcurrentUpdateSolrServer$Runner.run starting runner: org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer$Runner@11b6d603
[junit4] 2> 71960 T103 C14 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[0 (1442504224343588864), 1 (1442504224345686016)]} 0 252
[junit4] 2> 71965 T111 oascsi.ConcurrentUpdateSolrServer$Runner.run Status for: 0 is 200
[junit4] 2> 71966 T111 oascsi.ConcurrentUpdateSolrServer$Runner.run finished: org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer$Runner@11b6d603
[junit4] 2> 71971 T102 C14 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 71972 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: commit: start
[junit4] 2> 71972 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: commit: enter lock
[junit4] 2> 71973 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: commit: now prepare
[junit4] 2> 71973 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: prepareCommit: flush
[junit4] 2> 71974 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: index before flush
[junit4] 2> 71974 T102 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-102]: qtp1845849350-102 startFullFlush
[junit4] 2> 71975 T102 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-102]: anyChanges? numDocsInRam=2 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71976 T102 C14 oasu.LoggingInfoStream.message [DWFC][qtp1845849350-102]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 1 deleted terms (unique count=1) bytesUsed=165, segment=_2, aborting=false, numDocsInRAM=2, deleteQueue=DWDQ: [ generation: 7 ]]
[junit4] 2> 71977 T102 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-102]: flush postings as segment _2 numDocs=2
[junit4] 2> 71981 T102 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-102]: new segment has 0 deleted docs
[junit4] 2> 71982 T102 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-102]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 71982 T102 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-102]: flushedFiles=[_2_Lucene41_0.tim, _2.fdt, _2_Lucene41_0.doc, _2_Lucene41_0.tip, _2.fdx, _2.fnm]
[junit4] 2> 71983 T102 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-102]: flushed codec=Lucene42
[junit4] 2> 71983 T102 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-102]: flushed: segment=_2 ramUsed=0.063 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=2,377.723
[junit4] 2> 71984 T102 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-102]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 71985 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: publishFlushedSegment
[junit4] 2> 71985 T102 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-102]: push deletes 2 deleted terms (unique count=2) bytesUsed=1024 delGen=15 packetCount=1 totBytesUsed=1024
[junit4] 2> 71986 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: publish sets newSegment delGen=16 seg=_2(4.5):C2
[junit4] 2> 71986 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: now checkpoint "_2(4.5):C2" [1 segments ; isCommit = false]
[junit4] 2> 71987 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: 0 msec to checkpoint
[junit4] 2> 71988 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: apply all deletes during flush
[junit4] 2> 71989 T102 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-102]: applyDeletes: infos=[_2(4.5):C2] packetCount=1
[junit4] 2> 71990 T102 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-102]: applyDeletes took 1 msec
[junit4] 2> 71990 T102 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-102]: prune sis=org.apache.lucene.index.SegmentInfos@5d7487fb minGen=17 packetCount=1
[junit4] 2> 71991 T102 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-102]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 71991 T102 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-102]: qtp1845849350-102 finishFullFlush success=true
[junit4] 2> 71992 T102 C14 oasu.LoggingInfoStream.message [TMP][qtp1845849350-102]: findMerges: 1 segments
[junit4] 2> 71993 T102 C14 oasu.LoggingInfoStream.message [TMP][qtp1845849350-102]: seg=_2(4.5):C2 size=0.001 MB [floored]
[junit4] 2> 71993 T102 C14 oasu.LoggingInfoStream.message [TMP][qtp1845849350-102]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 71994 T102 C14 oasu.LoggingInfoStream.message [CMS][qtp1845849350-102]: now merge
[junit4] 2> 71994 T102 C14 oasu.LoggingInfoStream.message [CMS][qtp1845849350-102]: index: _2(4.5):C2
[junit4] 2> 71995 T102 C14 oasu.LoggingInfoStream.message [CMS][qtp1845849350-102]: no more merges pending; now return
[junit4] 2> 71995 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: startCommit(): start
[junit4] 2> 71996 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: startCommit index=_2(4.5):C2 changeCount=13
[junit4] 2> 71997 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: done all syncs: [_2.si, _2_Lucene41_0.tim, _2.fdt, _2_Lucene41_0.doc, _2_Lucene41_0.tip, _2.fdx, _2.fnm]
[junit4] 2> 71997 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: commit: pendingCommit != null
[junit4] 2> 71998 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: commit: wrote segments file "segments_4"
[junit4] 2> 71999 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: now checkpoint "_2(4.5):C2" [1 segments ; isCommit = true]
[junit4] 2> 72000 T102 C14 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@538330b2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d4419bd),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@538330b2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d4419bd),segFN=segments_4,generation=4}
[junit4] 2> 72000 T102 C14 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 72001 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: deleteCommits: now decRef commit "segments_3"
[junit4] 2> 72001 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: delete "_1.fdx"
[junit4] 2> 72002 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: delete "_1_Lucene41_0.doc"
[junit4] 2> 72002 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: 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> 72003 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: delete "_1.fdt"
[junit4] 2> 72004 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: unable to remove file "_1.fdt": java.io.IOException: MockDirectoryWrapper: file "_1.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 72004 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: delete "_1.si"
[junit4] 2> 72005 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: delete "_1_Lucene41_0.tim"
[junit4] 2> 72005 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: 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> 72006 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: delete "_1_Lucene41_0.tip"
[junit4] 2> 72006 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: delete "_1.fnm"
[junit4] 2> 72007 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: delete "segments_3"
[junit4] 2> 72008 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: 8 msec to checkpoint
[junit4] 2> 72008 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: commit: done
[junit4] 2> 72009 T102 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-102]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 72010 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 72010 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: flush at getReader
[junit4] 2> 72010 T102 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-102]: qtp1845849350-102 startFullFlush
[junit4] 2> 72011 T102 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-102]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 72012 T102 C14 oasu.LoggingInfoStream.message [DWFC][qtp1845849350-102]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 8 ]]
[junit4] 2> 72012 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: apply all deletes during flush
[junit4] 2> 72013 T102 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-102]: applyDeletes: no deletes; skipping
[junit4] 2> 72013 T102 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-102]: prune sis=org.apache.lucene.index.SegmentInfos@5d7487fb minGen=17 packetCount=0
[junit4] 2> 72015 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: return reader version=11 reader=StandardDirectoryReader(segments_4:11:nrt _2(4.5):C2)
[junit4] 2> 72016 T102 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-102]: qtp1845849350-102 finishFullFlush success=true
[junit4] 2> 72016 T102 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-102]: getReader took 6 msec
[junit4] 2> 72017 T102 C14 oass.SolrIndexSearcher.<init> Opening Searcher@5c3301f3 main
[junit4] 2> 72018 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: delete pending file _1_Lucene41_0.doc
[junit4] 2> 72019 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: delete "_1_Lucene41_0.doc"
[junit4] 2> 72019 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: 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> 72020 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: delete pending file _1.fdt
[junit4] 2> 72020 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: delete "_1.fdt"
[junit4] 2> 72021 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: unable to remove file "_1.fdt": java.io.IOException: MockDirectoryWrapper: file "_1.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 72021 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: delete pending file _1_Lucene41_0.tim
[junit4] 2> 72022 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: delete "_1_Lucene41_0.tim"
[junit4] 2> 72022 T102 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-102]: 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> 72023 T102 C14 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 72024 T108 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@5c3301f3 main{StandardDirectoryReader(segments_4:11:nrt _2(4.5):C2)}
[junit4] 2> 72025 T108 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 72049 T108 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5c3301f3 main{StandardDirectoryReader(segments_4:11:nrt _2(4.5):C2)}
[junit4] 2> 72051 T108 oasu.LoggingInfoStream.message [IFD][searcherExecutor-93-thread-1]: delete pending file _1_Lucene41_0.doc
[junit4] 2> 72051 T108 oasu.LoggingInfoStream.message [IFD][searcherExecutor-93-thread-1]: delete "_1_Lucene41_0.doc"
[junit4] 2> 72065 T108 oasu.LoggingInfoStream.message [IFD][searcherExecutor-93-thread-1]: delete pending file _1.fdt
[junit4] 2> 72067 T108 oasu.LoggingInfoStream.message [IFD][searcherExecutor-93-thread-1]: delete "_1.fdt"
[junit4] 2> 72088 T108 oasu.LoggingInfoStream.message [IFD][searcherExecutor-93-thread-1]: delete pending file _1_Lucene41_0.tim
[junit4] 2> 72088 T108 oasu.LoggingInfoStream.message [IFD][searcherExecutor-93-thread-1]: delete "_1_Lucene41_0.tim"
[junit4] 2> 72089 T102 C14 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 118
[junit4] 2> 72114 T102 C14 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2&rows=2} hits=2 status=0 QTime=3
[junit4] 2> 72133 T106 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-106]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 72134 T106 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-106]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 72135 T106 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-106]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 72136 T106 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-106]: flush at getReader
[junit4] 2> 72136 T106 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-106]: qtp1845849350-106 startFullFlush
[junit4] 2> 72137 T106 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-106]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 72138 T106 C14 oasu.LoggingInfoStream.message [DWFC][qtp1845849350-106]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 9 ]]
[junit4] 2> 72138 T106 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-106]: qtp1845849350-106: flush naked frozen global deletes
[junit4] 2> 72139 T106 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-106]: push deletes 1 deleted queries bytesUsed=32 delGen=19 packetCount=1 totBytesUsed=32
[junit4] 2> 72148 T106 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-106]: flush: push buffered deletes: 1 deleted queries bytesUsed=32
[junit4] 2> 72149 T106 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-106]: apply all deletes during flush
[junit4] 2> 72150 T106 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-106]: applyDeletes: infos=[_2(4.5):C2] packetCount=1
[junit4] 2> 72151 T106 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-106]: seg=_2(4.5):C2 segGen=17 coalesced deletes=[CoalescedDeletes(termSets=1,queries=1)] newDelCount=2 100% deleted
[junit4] 2> 72151 T106 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-106]: applyDeletes took 1 msec
[junit4] 2> 72152 T106 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-106]: now checkpoint "_2(4.5):C2/2" [1 segments ; isCommit = false]
[junit4] 2> 72153 T106 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-106]: 0 msec to checkpoint
[junit4] 2> 72153 T106 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-106]: drop 100% deleted segments: _2(4.5):C2/2
[junit4] 2> 72154 T106 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-106]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 72154 T106 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-106]: 0 msec to checkpoint
[junit4] 2> 72155 T106 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-106]: prune sis=org.apache.lucene.index.SegmentInfos@5d7487fb minGen=9223372036854775807 packetCount=1
[junit4] 2> 72161 T106 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-106]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 72161 T106 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-106]: return reader version=13 reader=StandardDirectoryReader(segments_4:13:nrt)
[junit4] 2> 72162 T106 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-106]: qtp1845849350-106 finishFullFlush success=true
[junit4] 2> 72162 T106 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-106]: getReader took 26 msec
[junit4] 2> 72163 T106 C14 oass.SolrIndexSearcher.<init> Opening Searcher@64ed9b24 realtime
[junit4] 2> 72163 T106 C14 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1442504224786087936)} 0 32
[junit4] 2> 72168 T111 oascsi.ConcurrentUpdateSolrServer$Runner.run starting runner: org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer$Runner@2b648c40
[junit4] 2> 72425 T100 C14 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[0 (1442504224832225280), 1 (1442504224834322432), 2 (1442504224836419584), 3 (1442504224842711040), 4 (1442504224843759616)]} 0 250
[junit4] 2> 72438 T111 oascsi.ConcurrentUpdateSolrServer$Runner.run Status for: 0 is 200
[junit4] 2> 72440 T111 oascsi.ConcurrentUpdateSolrServer$Runner.run finished: org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer$Runner@2b648c40
[junit4] 2> 72445 T103 C14 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 72446 T103 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-103]: commit: start
[junit4] 2> 72447 T103 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-103]: commit: enter lock
[junit4] 2> 72447 T103 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-103]: commit: now prepare
[junit4] 2> 72448 T103 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-103]: prepareCommit: flush
[junit4] 2> 72448 T103 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-103]: index before flush
[junit4] 2> 72449 T103 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-103]: qtp1845849350-103 startFullFlush
[junit4] 2> 72449 T103 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-103]: anyChanges? numDocsInRam=5 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 72450 T103 C14 oasu.LoggingInfoStream.message [DWFC][qtp1845849350-103]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 4 deleted terms (unique count=4) bytesUsed=660, segment=_3, aborting=false, numDocsInRAM=5, deleteQueue=DWDQ: [ generation: 10 ]]
[junit4] 2> 72451 T103 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-103]: flush postings as segment _3 numDocs=5
[junit4] 2> 72458 T103 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-103]: new segment has 0 deleted docs
[junit4] 2> 72459 T103 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-103]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 72459 T103 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-103]: flushedFiles=[_3.fdx, _3_Lucene41_0.doc, _3_Lucene41_0.tip, _3.fnm, _3_Lucene41_0.tim, _3.fdt]
[junit4] 2> 72460 T103 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-103]: flushed codec=Lucene42
[junit4] 2> 72461 T103 C14 oasu.LoggingInfoStream.message [DWPT][qtp1845849350-103]: flushed: segment=_3 ramUsed=0.064 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=4,969.555
[junit4] 2> 72462 T103 C14 oasu.LoggingInfoStream.message [DW][qtp1845849350-103]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 72462 T103 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-103]: publishFlushedSegment
[junit4] 2> 72463 T103 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-103]: push deletes 5 deleted terms (unique count=5) bytesUsed=1024 delGen=21 packetCount=1 totBytesUsed=1024
[junit4] 2> 72463 T103 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-103]: publish sets newSegment delGen=22 seg=_3(4.5):C5
[junit4] 2> 72464 T103 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-103]: now checkpoint "_3(4.5):C5" [1 segments ; isCommit = false]
[junit4] 2> 72464 T103 C14 oasu.LoggingInfoStream.message [IFD][qtp1845849350-103]: 0 msec to checkpoint
[junit4] 2> 72465 T103 C14 oasu.LoggingInfoStream.message [IW][qtp1845849350-103]: apply all deletes during flush
[junit4] 2> 72465 T103 C14 oasu.LoggingInfoStream.message [BD][qtp1845849350-103]: applyDelet
[...truncated too long message...]
olrCoreState Closing SolrCoreState
[junit4] 2> 298154 T97 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 298155 T97 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 298169 T97 C19 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: now flush at close waitForMerges=true
[junit4] 2> 298170 T97 C19 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: start flush: applyAllDeletes=true
[junit4] 2> 298171 T97 C19 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: index before flush _1l(4.5):C4 _1m(4.5):C1
[junit4] 2> 298171 T97 C19 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker startFullFlush
[junit4] 2> 298172 T97 C19 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 298180 T97 C19 oasu.LoggingInfoStream.message [DWFC][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 153 ]]
[junit4] 2> 298182 T97 C19 oasu.LoggingInfoStream.message [DWFC][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 153 ]]
[junit4] 2> 298183 T97 C19 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker finishFullFlush success=true
[junit4] 2> 298184 T97 C19 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: apply all deletes during flush
[junit4] 2> 298185 T97 C19 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: applyDeletes: no deletes; skipping
[junit4] 2> 298186 T97 C19 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@5d7487fb minGen=287 packetCount=0
[junit4] 2> 298187 T97 C19 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: now merge
[junit4] 2> 298195 T97 C19 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: index: _1l(4.5):C4 _1m(4.5):C1
[junit4] 2> 298196 T97 C19 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: no more merges pending; now return
[junit4] 2> 298199 T97 C19 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: waitForMerges
[junit4] 2> 298200 T97 C19 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: waitForMerges done
[junit4] 2> 298201 T97 C19 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: now call final commit()
[junit4] 2> 298201 T97 C19 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: commit: start
[junit4] 2> 298202 T97 C19 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: commit: enter lock
[junit4] 2> 298203 T97 C19 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: commit: now prepare
[junit4] 2> 298203 T97 C19 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: prepareCommit: flush
[junit4] 2> 298204 T97 C19 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: index before flush _1l(4.5):C4 _1m(4.5):C1
[junit4] 2> 298205 T97 C19 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker startFullFlush
[junit4] 2> 298205 T97 C19 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 298206 T97 C19 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: apply all deletes during flush
[junit4] 2> 298206 T97 C19 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: applyDeletes: no deletes; skipping
[junit4] 2> 298207 T97 C19 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@5d7487fb minGen=287 packetCount=0
[junit4] 2> 298208 T97 C19 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker finishFullFlush success=true
[junit4] 2> 298209 T97 C19 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: startCommit(): start
[junit4] 2> 298209 T97 C19 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: skip startCommit(): no changes pending
[junit4] 2> 298210 T97 C19 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: commit: pendingCommit == null; skip
[junit4] 2> 298210 T97 C19 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: commit: done
[junit4] 2> 298211 T97 C19 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[619FEC580107CFFD]-worker]: at close: _1l(4.5):C4 _1m(4.5):C1
[junit4] 2> 298253 T97 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 298267 T97 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 298268 T97 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleStreamingBinaryTest-1375679224393 [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleStreamingBinaryTest-1375679224393;done=false>>]
[junit4] 2> 298269 T97 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleStreamingBinaryTest-1375679224393
[junit4] 2> 298271 T97 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleStreamingBinaryTest-1375679224393/index [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleStreamingBinaryTest-1375679224393/index;done=false>>]
[junit4] 2> 298281 T97 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleStreamingBinaryTest-1375679224393/index
[junit4] 2> 298286 T97 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 298428 T97 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene40, sim=DefaultSimilarity, locale=sr__#Latn, timezone=Etc/GMT-9
[junit4] 2> NOTE: Mac OS X 10.8.4 x86_64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=2,threads=9,free=50116184,total=95420416
[junit4] 2> NOTE: All tests run in this JVM: [SolrExampleJettyTest, MultiCoreExampleJettyTest, SolrExceptionTest, TestCoreAdmin, SolrExampleStreamingBinaryTest]
[junit4] Completed in 232.59s, 27 tests, 1 error <<< FAILURES!
[...truncated 132 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: 125 minutes 25 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure