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/24 13:37:09 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/ibm-j9-jdk7) - Build # 7061
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/7061/
Java: 64bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
1 tests failed.
REGRESSION: org.apache.solr.client.solrj.SolrExampleBinaryTest.testUnicode
Error Message:
IOException occured when talking to server at: https://127.0.0.1:36851/solr/collection1
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:36851/solr/collection1
at __randomizedtesting.SeedInfo.seed([E13110CCDB408442:F8FDA4C679FA55B5]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:435)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:168)
at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:146)
at org.apache.solr.client.solrj.SolrExampleTests.testUnicode(SolrExampleTests.java:376)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
at java.lang.reflect.Method.invoke(Method.java:613)
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:780)
Caused by: org.apache.http.NoHttpResponseException: The target server failed to respond
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:95)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:62)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:254)
at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:289)
at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:252)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:191)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:717)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:522)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
... 45 more
Build Log:
[...truncated 11007 lines...]
[junit4] Suite: org.apache.solr.client.solrj.SolrExampleBinaryTest
[junit4] 2> log4j:WARN No such property [conversionPattern] in org.apache.solr.util.SolrLogLayout.
[junit4] 2> 367 T24 oas.SolrJettyTestBase.beforeSolrJettyTestBase Randomized ssl (true) and clientAuth (false)
[junit4] 2> 372 T24 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/./solrtest-SolrExampleBinaryTest-1377344000441
[junit4] 2> 373 T24 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 563 T24 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1370 T24 oejus.SslContextFactory.doStart Enabled Protocols [TLSv1] of [SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 1397 T24 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:36851
[junit4] 2> 1407 T24 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1428 T24 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1429 T24 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr
[junit4] 2> 1429 T24 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/'
[junit4] 2> 1536 T24 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/solr.xml
[junit4] 2> 1787 T24 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 1795 T24 oasc.CoreContainer.<init> New CoreContainer 1276227018
[junit4] 2> 1796 T24 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/]
[junit4] 2> 1832 T24 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 1836 T24 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1837 T24 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 1838 T24 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1839 T24 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1840 T24 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1841 T24 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1842 T24 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1843 T24 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1857 T24 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 1987 T24 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr
[junit4] 2> 2016 T24 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/
[junit4] 2> 2019 T24 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 2021 T36 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1
[junit4] 2> 2022 T36 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/'
[junit4] 2> 2309 T36 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 2311 T36 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/extraction/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/../../../contrib/extraction/lib).
[junit4] 2> 2311 T36 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/../../../dist).
[junit4] 2> 2312 T36 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/clustering/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/../../../contrib/clustering/lib).
[junit4] 2> 2313 T36 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/../../../dist).
[junit4] 2> 2313 T36 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/langid/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/../../../contrib/langid/lib).
[junit4] 2> 2314 T36 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/../../../dist).
[junit4] 2> 2314 T36 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/velocity/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/../../../contrib/velocity/lib).
[junit4] 2> 2315 T36 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/../../../dist).
[junit4] 2> 2406 T36 oasu.SolrIndexConfig.<init> IndexWriter infoStream solr logging is enabled
[junit4] 2> 2411 T36 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 2556 T36 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2561 T36 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2666 T36 oass.IndexSchema.readSchema [null] Schema name=example
[junit4] 2> 3732 T36 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3877 T36 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 3890 T36 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 4151 T36 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 4158 T36 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleBinaryTest-1377344000441/
[junit4] 2> 4161 T36 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
[junit4] 2> 4169 T36 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4] 2> 4170 T36 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
[junit4] 2> 4185 T36 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleBinaryTest-1377344000441
[junit4] 2> 4186 T36 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleBinaryTest-1377344000441/index/
[junit4] 2> 4187 T36 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleBinaryTest-1377344000441/index' doesn't exist. Creating new index...
[junit4] 2> 4197 T36 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleBinaryTest-1377344000441/index
[junit4] 2> 4225 T36 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-3-thread-1]: init: current segments file is "null"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@d0c93841
[junit4] 2> 4227 T36 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-3-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 4228 T36 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-3-thread-1]: 0 msec to checkpoint
[junit4] 2> 4229 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: init: create=true
[junit4] 2> 4230 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]:
[junit4] 2> dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b875d92a lockFactory=org.apache.lucene.store.NativeFSLockFactory@6404d098)
[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=Lucene45
[junit4] 2> infoStream=org.apache.solr.update.LoggingInfoStream
[junit4] 2> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> indexerThreadPool=org.apache.lucene.index.ThreadAffinityDocumentsWriterThreadPool@911a8d64
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2>
[junit4] 2> 4231 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: now flush at close waitForMerges=true
[junit4] 2> 4232 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: start flush: applyAllDeletes=true
[junit4] 2> 4233 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: index before flush
[junit4] 2> 4233 T36 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-3-thread-1]: coreLoadExecutor-3-thread-1 startFullFlush
[junit4] 2> 4234 T36 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-3-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 4236 T36 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-3-thread-1]: coreLoadExecutor-3-thread-1 finishFullFlush success=true
[junit4] 2> 4237 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: apply all deletes during flush
[junit4] 2> 4238 T36 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-3-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@78676ec2 minGen=9223372036854775807 packetCount=0
[junit4] 2> 4239 T36 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-3-thread-1]: now merge
[junit4] 2> 4240 T36 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-3-thread-1]: index:
[junit4] 2> 4240 T36 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-3-thread-1]: no more merges pending; now return
[junit4] 2> 4241 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: waitForMerges
[junit4] 2> 4242 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: waitForMerges done
[junit4] 2> 4243 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: now call final commit()
[junit4] 2> 4243 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: commit: start
[junit4] 2> 4244 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: commit: enter lock
[junit4] 2> 4245 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: commit: now prepare
[junit4] 2> 4248 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: prepareCommit: flush
[junit4] 2> 4249 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: index before flush
[junit4] 2> 4250 T36 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-3-thread-1]: coreLoadExecutor-3-thread-1 startFullFlush
[junit4] 2> 4250 T36 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-3-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 4251 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: apply all deletes during flush
[junit4] 2> 4252 T36 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-3-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@78676ec2 minGen=9223372036854775807 packetCount=0
[junit4] 2> 4253 T36 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-3-thread-1]: coreLoadExecutor-3-thread-1 finishFullFlush success=true
[junit4] 2> 4254 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: startCommit(): start
[junit4] 2> 4254 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: startCommit index= changeCount=1
[junit4] 2> 4258 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: done all syncs: []
[junit4] 2> 4259 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: commit: pendingCommit != null
[junit4] 2> 4260 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: commit: wrote segments file "segments_1"
[junit4] 2> 4261 T36 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-3-thread-1]: now checkpoint "" [0 segments ; isCommit = true]
[junit4] 2> 4264 T36 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b875d92a lockFactory=org.apache.lucene.store.NativeFSLockFactory@6404d098),segFN=segments_1,generation=1}
[junit4] 2> 4266 T36 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 4266 T36 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-3-thread-1]: 5 msec to checkpoint
[junit4] 2> 4267 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: commit: done
[junit4] 2> 4268 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: at close:
[junit4] 2> 4273 T36 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 4274 T36 oasc.SolrCore.initWriters adding lazy queryResponseWriter: solr.VelocityResponseWriter
[junit4] 2> 4275 T36 oasc.SolrCore.initWriters created velocity: solr.VelocityResponseWriter
[junit4] 2> 4280 T36 oasc.SolrCore.initWriters created xslt: solr.XSLTResponseWriter
[junit4] 2> 4280 T36 oasr.XSLTResponseWriter.init xsltCacheLifetimeSeconds=5
[junit4] 2> 4416 T36 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 4426 T36 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 4428 T36 oasc.RequestHandlers.initHandlersFromConfig created /query: solr.SearchHandler
[junit4] 2> 4431 T36 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 4432 T36 oasc.RequestHandlers.initHandlersFromConfig created /browse: solr.SearchHandler
[junit4] 2> 4437 T36 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 4440 T36 oasc.RequestHandlers.initHandlersFromConfig created /update/json: solr.JsonUpdateRequestHandler
[junit4] 2> 4443 T36 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: solr.CSVRequestHandler
[junit4] 2> 4443 T36 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
[junit4] 2> 4445 T36 oasc.RequestHandlers.initHandlersFromConfig created /update/extract: solr.extraction.ExtractingRequestHandler
[junit4] 2> 4445 T36 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.FieldAnalysisRequestHandler
[junit4] 2> 4446 T36 oasc.RequestHandlers.initHandlersFromConfig created /analysis/field: solr.FieldAnalysisRequestHandler
[junit4] 2> 4446 T36 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
[junit4] 2> 4447 T36 oasc.RequestHandlers.initHandlersFromConfig created /analysis/document: solr.DocumentAnalysisRequestHandler
[junit4] 2> 4450 T36 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 4453 T36 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
[junit4] 2> 4457 T36 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 4468 T36 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 4469 T36 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 4469 T36 oasc.RequestHandlers.initHandlersFromConfig created /spell: solr.SearchHandler
[junit4] 2> 4470 T36 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 4471 T36 oasc.RequestHandlers.initHandlersFromConfig created /tvrh: solr.SearchHandler
[junit4] 2> 4471 T36 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: org.apache.solr.handler.js.JavaScriptRequestHandler
[junit4] 2> 4472 T36 oasc.RequestHandlers.initHandlersFromConfig created /js: org.apache.solr.handler.js.JavaScriptRequestHandler
[junit4] 2> 4472 T36 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 4473 T36 oasc.RequestHandlers.initHandlersFromConfig created /terms: solr.SearchHandler
[junit4] 2> 4474 T36 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 4474 T36 oasc.RequestHandlers.initHandlersFromConfig created /elevate: solr.SearchHandler
[junit4] 2> 4498 T36 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 4503 T36 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 4505 T36 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 4529 T36 oasu.CommitTracker.<init> Hard AutoCommit: if uncommited for 15000ms;
[junit4] 2> 4530 T36 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 4533 T36 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-3-thread-1]: init: current segments file is "segments_1"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@d0c93841
[junit4] 2> 4534 T36 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-3-thread-1]: init: load commit "segments_1"
[junit4] 2> 4535 T36 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b875d92a lockFactory=org.apache.lucene.store.NativeFSLockFactory@6404d098),segFN=segments_1,generation=1}
[junit4] 2> 4535 T36 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 4536 T36 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-3-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 4537 T36 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-3-thread-1]: 0 msec to checkpoint
[junit4] 2> 4537 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: init: create=false
[junit4] 2> 4538 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]:
[junit4] 2> dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b875d92a lockFactory=org.apache.lucene.store.NativeFSLockFactory@6404d098)
[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=Lucene45
[junit4] 2> infoStream=org.apache.solr.update.LoggingInfoStream
[junit4] 2> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> indexerThreadPool=org.apache.lucene.index.ThreadAffinityDocumentsWriterThreadPool@9ce36960
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2>
[junit4] 2> 4541 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: flush at getReader
[junit4] 2> 4545 T36 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-3-thread-1]: coreLoadExecutor-3-thread-1 startFullFlush
[junit4] 2> 4546 T36 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-3-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 4547 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: apply all deletes during flush
[junit4] 2> 4548 T36 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-3-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@e6f3b520 minGen=9223372036854775807 packetCount=0
[junit4] 2> 4551 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
[junit4] 2> 4551 T36 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-3-thread-1]: coreLoadExecutor-3-thread-1 finishFullFlush success=true
[junit4] 2> 4552 T36 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-3-thread-1]: getReader took 11 msec
[junit4] 2> 4560 T36 oass.SolrIndexSearcher.<init> Opening Searcher@59f56737 main
[junit4] 2> 4568 T36 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 4578 T36 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> 4589 T36 oashc.SpellCheckComponent.inform No queryConverter defined, using default converter
[junit4] 2> 4593 T36 oashc.QueryElevationComponent.inform Loading QueryElevation from: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/conf/elevate.xml
[junit4] 2> 4639 T36 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 4640 T37 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@59f56737 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 4641 T36 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 4643 T24 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1
[junit4] 2> 4646 T24 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 4648 T24 oas.SolrJettyTestBase.createJetty Jetty Assigned Port#36851
[junit4] 2> 4681 T24 oas.SolrTestCaseJ4.setUp ###Starting testContentStreamRequest
[junit4] 2> 4691 T24 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> ASYNC NEW_CORE C0 name=collection1 org.apache.solr.core.SolrCore@ca5c276d
[junit4] 2> 4718 T37 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+firstSearcher+warming+in+solrconfig.xml&distrib=false&event=firstSearcher} hits=0 status=0 QTime=76
[junit4] 2> 4720 T37 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 4721 T37 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
[junit4] 2> 4721 T37 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
[junit4] 2> 4722 T37 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@59f56737 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> ASYNC NEW_CORE C1 name=collection1 org.apache.solr.core.SolrCore@ca5c276d
[junit4] 2> 5790 T35 C1 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 5792 T35 C1 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 5793 T35 C1 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 5794 T35 C1 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: flush at getReader
[junit4] 2> 5794 T35 C1 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: qtp1589127657-35 startFullFlush
[junit4] 2> 5795 T35 C1 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 5796 T35 C1 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: qtp1589127657-35: flush naked frozen global deletes
[junit4] 2> 5801 T35 C1 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: push deletes 1 deleted queries bytesUsed=36 delGen=2 packetCount=1 totBytesUsed=36
[junit4] 2> 5802 T35 C1 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: flush: push buffered deletes: 1 deleted queries bytesUsed=36
[junit4] 2> 5817 T35 C1 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: apply all deletes during flush
[junit4] 2> 5818 T35 C1 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: prune sis=org.apache.lucene.index.SegmentInfos@e6f3b520 minGen=9223372036854775807 packetCount=1
[junit4] 2> 5819 T35 C1 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 5820 T35 C1 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
[junit4] 2> 5821 T35 C1 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: qtp1589127657-35 finishFullFlush success=true
[junit4] 2> 5822 T35 C1 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: getReader took 28 msec
[junit4] 2> 5825 T35 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {deleteByQuery=*:* (-1444249868213157888)} 0 113
[junit4] 2> ASYNC NEW_CORE C2 name=collection1 org.apache.solr.core.SolrCore@ca5c276d
[junit4] 2> 5975 T28 C2 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 5976 T28 C2 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 5977 T28 C2 oasu.LoggingInfoStream.message [DW][qtp1589127657-28]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 5978 T28 C2 oasu.LoggingInfoStream.message [IW][qtp1589127657-28]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
[junit4] 2> 5979 T28 C2 oasu.LoggingInfoStream.message [DW][qtp1589127657-28]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 5980 T28 C2 oass.SolrIndexSearcher.<init> Opening Searcher@1875efd2 main
[junit4] 2> 5982 T37 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1875efd2 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 5982 T28 C2 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 5983 T37 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 5984 T37 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1875efd2 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 5985 T28 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&commit=true&version=2&waitSearcher=true&wt=javabin} {commit=} 0 10
[junit4] 2> 5995 T33 C2 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&version=2&wt=javabin} hits=0 status=0 QTime=1
[junit4] 2> 6188 T35 C2 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 6189 T35 C2 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: start
[junit4] 2> 6189 T35 C2 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: enter lock
[junit4] 2> 6190 T35 C2 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: now prepare
[junit4] 2> 6191 T35 C2 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: prepareCommit: flush
[junit4] 2> 6192 T35 C2 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: index before flush
[junit4] 2> 6192 T35 C2 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: qtp1589127657-35 startFullFlush
[junit4] 2> 6193 T35 C2 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: anyChanges? numDocsInRam=10 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6194 T35 C2 oasu.LoggingInfoStream.message [DWFC][qtp1589127657-35]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 9 deleted terms (unique count=9) bytesUsed=2142, segment=_0, aborting=false, numDocsInRAM=10, deleteQueue=DWDQ: [ generation: 2 ]]
[junit4] 2> 6197 T35 C2 oasu.LoggingInfoStream.message [DWPT][qtp1589127657-35]: flush postings as segment _0 numDocs=10
[junit4] 2> ASYNC NEW_CORE C3 name=collection1 org.apache.solr.core.SolrCore@ca5c276d
[junit4] 2> 6270 T35 C3 oasu.LoggingInfoStream.message [DWPT][qtp1589127657-35]: new segment has 0 deleted docs
[junit4] 2> 6271 T35 C3 oasu.LoggingInfoStream.message [DWPT][qtp1589127657-35]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 6272 T35 C3 oasu.LoggingInfoStream.message [DWPT][qtp1589127657-35]: flushedFiles=[_0_Lucene41_0.pos, _0.fnm, _0.nvm, _0_Lucene41_0.tim, _0_Lucene41_0.doc, _0_Lucene41_0.tip, _0.fdt, _0.fdx, _0.nvd]
[junit4] 2> 6273 T35 C3 oasu.LoggingInfoStream.message [DWPT][qtp1589127657-35]: flushed codec=Lucene45
[junit4] 2> 6275 T35 C3 oasu.LoggingInfoStream.message [DWPT][qtp1589127657-35]: flushed: segment=_0 ramUsed=0.102 MB newFlushedSize(includes docstores)=0.004 MB docs/MB=2,309.13
[junit4] 2> 6279 T35 C3 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 6281 T35 C3 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: publishFlushedSegment
[junit4] 2> 6282 T35 C3 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: push deletes 10 deleted terms (unique count=10) bytesUsed=1024 delGen=4 packetCount=1 totBytesUsed=1024
[junit4] 2> 6285 T35 C3 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: publish sets newSegment delGen=5 seg=_0(4.5):C10
[junit4] 2> 6286 T35 C3 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: now checkpoint "_0(4.5):C10" [1 segments ; isCommit = false]
[junit4] 2> 6287 T35 C3 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: 0 msec to checkpoint
[junit4] 2> 6287 T35 C3 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: apply all deletes during flush
[junit4] 2> 6288 T35 C3 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: applyDeletes: infos=[_0(4.5):C10] packetCount=1
[junit4] 2> 6289 T35 C3 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: applyDeletes took 1 msec
[junit4] 2> 6289 T35 C3 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: prune sis=org.apache.lucene.index.SegmentInfos@e6f3b520 minGen=6 packetCount=1
[junit4] 2> 6290 T35 C3 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 6290 T35 C3 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: qtp1589127657-35 finishFullFlush success=true
[junit4] 2> 6292 T35 C3 oasu.LoggingInfoStream.message [TMP][qtp1589127657-35]: findMerges: 1 segments
[junit4] 2> 6295 T35 C3 oasu.LoggingInfoStream.message [TMP][qtp1589127657-35]: seg=_0(4.5):C10 size=0.004 MB [floored]
[junit4] 2> 6296 T35 C3 oasu.LoggingInfoStream.message [TMP][qtp1589127657-35]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 6296 T35 C3 oasu.LoggingInfoStream.message [CMS][qtp1589127657-35]: now merge
[junit4] 2> 6297 T35 C3 oasu.LoggingInfoStream.message [CMS][qtp1589127657-35]: index: _0(4.5):C10
[junit4] 2> 6298 T35 C3 oasu.LoggingInfoStream.message [CMS][qtp1589127657-35]: no more merges pending; now return
[junit4] 2> 6298 T35 C3 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: startCommit(): start
[junit4] 2> 6299 T35 C3 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: startCommit index=_0(4.5):C10 changeCount=3
[junit4] 2> 6302 T35 C3 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: done all syncs: [_0.si, _0_Lucene41_0.pos, _0_Lucene41_0.doc, _0_Lucene41_0.tim, _0.nvm, _0.fnm, _0.fdt, _0_Lucene41_0.tip, _0.fdx, _0.nvd]
[junit4] 2> 6302 T35 C3 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: pendingCommit != null
[junit4] 2> 6303 T35 C3 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: wrote segments file "segments_2"
[junit4] 2> 6304 T35 C3 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: now checkpoint "_0(4.5):C10" [1 segments ; isCommit = true]
[junit4] 2> 6304 T35 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b875d92a lockFactory=org.apache.lucene.store.NativeFSLockFactory@6404d098),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b875d92a lockFactory=org.apache.lucene.store.NativeFSLockFactory@6404d098),segFN=segments_2,generation=2}
[junit4] 2> 6305 T35 C3 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 6307 T35 C3 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: deleteCommits: now decRef commit "segments_1"
[junit4] 2> 6308 T35 C3 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: delete "segments_1"
[junit4] 2> 6309 T35 C3 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: 4 msec to checkpoint
[junit4] 2> 6309 T35 C3 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: done
[junit4] 2> 6310 T35 C3 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6310 T35 C3 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 6311 T35 C3 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: flush at getReader
[junit4] 2> 6311 T35 C3 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: qtp1589127657-35 startFullFlush
[junit4] 2> 6312 T35 C3 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6313 T35 C3 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: apply all deletes during flush
[junit4] 2> 6313 T35 C3 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: applyDeletes: no deletes; skipping
[junit4] 2> 6314 T35 C3 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: prune sis=org.apache.lucene.index.SegmentInfos@e6f3b520 minGen=6 packetCount=0
[junit4] 2> 6331 T35 C3 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: return reader version=3 reader=StandardDirectoryReader(segments_2:3:nrt _0(4.5):C10)
[junit4] 2> 6332 T35 C3 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: qtp1589127657-35 finishFullFlush success=true
[junit4] 2> 6332 T35 C3 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: getReader took 21 msec
[junit4] 2> 6333 T35 C3 oass.SolrIndexSearcher.<init> Opening Searcher@e06b572d main
[junit4] 2> 6334 T35 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 6334 T37 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@e06b572d main{StandardDirectoryReader(segments_2:3:nrt _0(4.5):C10)}
[junit4] 2> 6335 T37 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 6336 T37 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e06b572d main{StandardDirectoryReader(segments_2:3:nrt _0(4.5):C10)}
[junit4] 2> 6337 T35 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&commit=true&version=2&waitSearcher=true&wt=javabin} {add=[0553573403 (1444249868611616768), 0553579908 (1444249868680822784), 055357342X (1444249868683968512), 0553293354 (1444249868685017088), 0812521390 (1444249868687114240), 0812550706 (1444249868689211392), 0441385532 (1444249868691308544), 0380014300 (1444249868693405696), 0805080481 (1444249868695502848), 080508049X (1444249868701794304)],commit=} 0 246
[junit4] 2> 6346 T33 C3 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&version=2&wt=javabin} hits=10 status=0 QTime=5
[junit4] 2> 6357 T24 oas.SolrTestCaseJ4.tearDown ###Ending testContentStreamRequest
[junit4] 2> 6378 T24 oas.SolrTestCaseJ4.setUp ###Starting testStatistics
[junit4] 2> 6386 T32 C3 oasu.LoggingInfoStream.message [DW][qtp1589127657-32]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6387 T32 C3 oasu.LoggingInfoStream.message [IW][qtp1589127657-32]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 6388 T32 C3 oasu.LoggingInfoStream.message [DW][qtp1589127657-32]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6389 T32 C3 oasu.LoggingInfoStream.message [IW][qtp1589127657-32]: flush at getReader
[junit4] 2> 6389 T32 C3 oasu.LoggingInfoStream.message [DW][qtp1589127657-32]: qtp1589127657-32 startFullFlush
[junit4] 2> 6390 T32 C3 oasu.LoggingInfoStream.message [DW][qtp1589127657-32]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6391 T32 C3 oasu.LoggingInfoStream.message [DW][qtp1589127657-32]: qtp1589127657-32: flush naked frozen global deletes
[junit4] 2> 6392 T32 C3 oasu.LoggingInfoStream.message [BD][qtp1589127657-32]: push deletes 1 deleted queries bytesUsed=36 delGen=8 packetCount=1 totBytesUsed=36
[junit4] 2> 6392 T32 C3 oasu.LoggingInfoStream.message [DW][qtp1589127657-32]: flush: push buffered deletes: 1 deleted queries bytesUsed=36
[junit4] 2> 6393 T32 C3 oasu.LoggingInfoStream.message [IW][qtp1589127657-32]: apply all deletes during flush
[junit4] 2> 6394 T32 C3 oasu.LoggingInfoStream.message [BD][qtp1589127657-32]: applyDeletes: infos=[_0(4.5):C10] packetCount=1
[junit4] 2> 6417 T32 C3 oasu.LoggingInfoStream.message [BD][qtp1589127657-32]: seg=_0(4.5):C10 segGen=6 coalesced deletes=[CoalescedDeletes(termSets=1,queries=1)] newDelCount=10 100% deleted
[junit4] 2> ASYNC NEW_CORE C4 name=collection1 org.apache.solr.core.SolrCore@ca5c276d
[junit4] 2> 6431 T32 C4 oasu.LoggingInfoStream.message [BD][qtp1589127657-32]: applyDeletes took 37 msec
[junit4] 2> 6431 T32 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-32]: now checkpoint "_0(4.5):C10/10" [1 segments ; isCommit = false]
[junit4] 2> 6432 T32 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-32]: 0 msec to checkpoint
[junit4] 2> 6432 T32 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-32]: drop 100% deleted segments: _0(4.5):C10/10
[junit4] 2> 6433 T32 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-32]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 6434 T32 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-32]: 0 msec to checkpoint
[junit4] 2> 6434 T32 C4 oasu.LoggingInfoStream.message [BD][qtp1589127657-32]: prune sis=org.apache.lucene.index.SegmentInfos@e6f3b520 minGen=9223372036854775807 packetCount=1
[junit4] 2> 6435 T32 C4 oasu.LoggingInfoStream.message [BD][qtp1589127657-32]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 6435 T32 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-32]: return reader version=5 reader=StandardDirectoryReader(segments_2:5:nrt)
[junit4] 2> 6436 T32 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-32]: qtp1589127657-32 finishFullFlush success=true
[junit4] 2> 6436 T32 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-32]: getReader took 47 msec
[junit4] 2> 6437 T32 C4 oass.SolrIndexSearcher.<init> Opening Searcher@aa3e4064 realtime
[junit4] 2> 6438 T32 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {deleteByQuery=*:* (-1444249868911509504)} 0 53
[junit4] 2> 6445 T35 C4 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 6446 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: start
[junit4] 2> 6446 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: enter lock
[junit4] 2> 6447 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: now prepare
[junit4] 2> 6449 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: prepareCommit: flush
[junit4] 2> 6450 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: index before flush
[junit4] 2> 6453 T35 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: qtp1589127657-35 startFullFlush
[junit4] 2> 6454 T35 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6459 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: apply all deletes during flush
[junit4] 2> 6460 T35 C4 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: prune sis=org.apache.lucene.index.SegmentInfos@e6f3b520 minGen=9223372036854775807 packetCount=0
[junit4] 2> 6461 T35 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: qtp1589127657-35 finishFullFlush success=true
[junit4] 2> 6462 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: startCommit(): start
[junit4] 2> 6463 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: startCommit index= changeCount=6
[junit4] 2> 6464 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: done all syncs: []
[junit4] 2> 6464 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: pendingCommit != null
[junit4] 2> 6465 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: wrote segments file "segments_3"
[junit4] 2> 6466 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: now checkpoint "" [0 segments ; isCommit = true]
[junit4] 2> 6467 T35 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b875d92a lockFactory=org.apache.lucene.store.NativeFSLockFactory@6404d098),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b875d92a lockFactory=org.apache.lucene.store.NativeFSLockFactory@6404d098),segFN=segments_3,generation=3}
[junit4] 2> 6468 T35 C4 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 6469 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: deleteCommits: now decRef commit "segments_2"
[junit4] 2> 6469 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: delete "_0.si"
[junit4] 2> 6471 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: delete "segments_2"
[junit4] 2> 6473 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: delete "_0_Lucene41_0.pos"
[junit4] 2> 6476 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: 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> 6478 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: delete "_0_Lucene41_0.doc"
[junit4] 2> 6481 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: 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> 6483 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: delete "_0_Lucene41_0.tim"
[junit4] 2> 6485 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: 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> 6487 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: delete "_0.nvm"
[junit4] 2> 6489 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: delete "_0.fnm"
[junit4] 2> 6491 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: delete "_0.fdt"
[junit4] 2> 6493 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: unable to remove file "_0.fdt": java.io.IOException: MockDirectoryWrapper: file "_0.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 6495 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: delete "_0_Lucene41_0.tip"
[junit4] 2> 6497 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: delete "_0.fdx"
[junit4] 2> 6499 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: delete "_0.nvd"
[junit4] 2> 6500 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: unable to remove file "_0.nvd": java.io.IOException: MockDirectoryWrapper: file "_0.nvd" is still open: cannot delete; Will re-try later.
[junit4] 2> 6501 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: 35 msec to checkpoint
[junit4] 2> 6502 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: done
[junit4] 2> 6503 T35 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6504 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
[junit4] 2> 6505 T35 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6506 T35 C4 oass.SolrIndexSearcher.<init> Opening Searcher@b25cdacc main
[junit4] 2> 6507 T35 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 6507 T37 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@b25cdacc main{StandardDirectoryReader(segments_2:5:nrt)}
[junit4] 2> 6508 T37 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 6508 T37 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b25cdacc main{StandardDirectoryReader(segments_2:5:nrt)}
[junit4] 2> 6509 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete pending file _0_Lucene41_0.pos
[junit4] 2> 6510 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete "_0_Lucene41_0.pos"
[junit4] 2> 6510 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete pending file _0_Lucene41_0.doc
[junit4] 2> 6511 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete "_0_Lucene41_0.doc"
[junit4] 2> 6511 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete pending file _0_Lucene41_0.tim
[junit4] 2> 6512 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete "_0_Lucene41_0.tim"
[junit4] 2> 6513 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete pending file _0.fdt
[junit4] 2> 6513 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete "_0.fdt"
[junit4] 2> 6514 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete pending file _0.nvd
[junit4] 2> 6514 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete "_0.nvd"
[junit4] 2> 6515 T35 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&commit=true&version=2&waitSearcher=true&wt=javabin} {commit=} 0 70
[junit4] 2> 6520 T28 C4 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&version=2&wt=javabin} hits=0 status=0 QTime=0
[junit4] 2> 6528 T33 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[doc0 (1444249869059358720)]} 0 3
[junit4] 2> 6536 T32 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[doc1 (1444249869068795904)]} 0 2
[junit4] 2> 6542 T35 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[doc2 (1444249869075087360)]} 0 1
[junit4] 2> 6548 T28 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[doc3 (1444249869081378816)]} 0 2
[junit4] 2> 6557 T33 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[doc4 (1444249869090816000)]} 0 1
[junit4] 2> 6563 T32 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[doc5 (1444249869097107456)]} 0 1
[junit4] 2> 6569 T35 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[doc6 (1444249869103398912)]} 0 1
[junit4] 2> 6579 T28 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[doc7 (1444249869112836096)]} 0 2
[junit4] 2> 6587 T33 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[doc8 (1444249869122273280)]} 0 1
[junit4] 2> 6593 T32 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[doc9 (1444249869128564736)]} 0 1
[junit4] 2> 6601 T35 C4 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 6602 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: start
[junit4] 2> 6603 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: enter lock
[junit4] 2> 6603 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: now prepare
[junit4] 2> 6604 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: prepareCommit: flush
[junit4] 2> 6605 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: index before flush
[junit4] 2> 6605 T35 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: qtp1589127657-35 startFullFlush
[junit4] 2> 6606 T35 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: anyChanges? numDocsInRam=10 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6607 T35 C4 oasu.LoggingInfoStream.message [DWFC][qtp1589127657-35]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 9 deleted terms (unique count=9) bytesUsed=2088, segment=_1, aborting=false, numDocsInRAM=10, deleteQueue=DWDQ: [ generation: 6 ]]
[junit4] 2> 6608 T35 C4 oasu.LoggingInfoStream.message [DWPT][qtp1589127657-35]: flush postings as segment _1 numDocs=10
[junit4] 2> 6624 T35 C4 oasu.LoggingInfoStream.message [DWPT][qtp1589127657-35]: new segment has 0 deleted docs
[junit4] 2> 6625 T35 C4 oasu.LoggingInfoStream.message [DWPT][qtp1589127657-35]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 6626 T35 C4 oasu.LoggingInfoStream.message [DWPT][qtp1589127657-35]: flushedFiles=[_1.nvd, _1_Lucene41_0.pos, _1_Lucene41_0.tim, _1_Lucene41_0.doc, _1.fnm, _1.nvm, _1_Lucene41_0.tip, _1.fdt, _1.fdx]
[junit4] 2> 6627 T35 C4 oasu.LoggingInfoStream.message [DWPT][qtp1589127657-35]: flushed codec=Lucene45
[junit4] 2> 6629 T35 C4 oasu.LoggingInfoStream.message [DWPT][qtp1589127657-35]: flushed: segment=_1 ramUsed=0.083 MB newFlushedSize(includes docstores)=0.002 MB docs/MB=6,150.006
[junit4] 2> 6636 T35 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 6637 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: publishFlushedSegment
[junit4] 2> 6638 T35 C4 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: push deletes 10 deleted terms (unique count=10) bytesUsed=1024 delGen=11 packetCount=1 totBytesUsed=1024
[junit4] 2> 6638 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: publish sets newSegment delGen=12 seg=_1(4.5):C10
[junit4] 2> 6639 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: now checkpoint "_1(4.5):C10" [1 segments ; isCommit = false]
[junit4] 2> 6640 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: 0 msec to checkpoint
[junit4] 2> 6641 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: apply all deletes during flush
[junit4] 2> 6642 T35 C4 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: applyDeletes: infos=[_1(4.5):C10] packetCount=1
[junit4] 2> 6643 T35 C4 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: applyDeletes took 1 msec
[junit4] 2> 6644 T35 C4 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: prune sis=org.apache.lucene.index.SegmentInfos@e6f3b520 minGen=13 packetCount=1
[junit4] 2> 6644 T35 C4 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 6645 T35 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: qtp1589127657-35 finishFullFlush success=true
[junit4] 2> 6646 T35 C4 oasu.LoggingInfoStream.message [TMP][qtp1589127657-35]: findMerges: 1 segments
[junit4] 2> 6647 T35 C4 oasu.LoggingInfoStream.message [TMP][qtp1589127657-35]: seg=_1(4.5):C10 size=0.001 MB [floored]
[junit4] 2> 6648 T35 C4 oasu.LoggingInfoStream.message [TMP][qtp1589127657-35]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 6649 T35 C4 oasu.LoggingInfoStream.message [CMS][qtp1589127657-35]: now merge
[junit4] 2> 6649 T35 C4 oasu.LoggingInfoStream.message [CMS][qtp1589127657-35]: index: _1(4.5):C10
[junit4] 2> 6650 T35 C4 oasu.LoggingInfoStream.message [CMS][qtp1589127657-35]: no more merges pending; now return
[junit4] 2> 6651 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: startCommit(): start
[junit4] 2> 6652 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: startCommit index=_1(4.5):C10 changeCount=9
[junit4] 2> 6653 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: done all syncs: [_1.nvd, _1.si, _1_Lucene41_0.pos, _1_Lucene41_0.doc, _1_Lucene41_0.tim, _1.nvm, _1.fnm, _1.fdt, _1_Lucene41_0.tip, _1.fdx]
[junit4] 2> 6654 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: pendingCommit != null
[junit4] 2> 6655 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: wrote segments file "segments_4"
[junit4] 2> 6655 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: now checkpoint "_1(4.5):C10" [1 segments ; isCommit = true]
[junit4] 2> 6656 T35 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b875d92a lockFactory=org.apache.lucene.store.NativeFSLockFactory@6404d098),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b875d92a lockFactory=org.apache.lucene.store.NativeFSLockFactory@6404d098),segFN=segments_4,generation=4}
[junit4] 2> 6657 T35 C4 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 6658 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: deleteCommits: now decRef commit "segments_3"
[junit4] 2> 6659 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: delete "segments_3"
[junit4] 2> 6659 T35 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: 4 msec to checkpoint
[junit4] 2> 6660 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: done
[junit4] 2> 6662 T35 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6664 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 6666 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: flush at getReader
[junit4] 2> 6668 T35 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: qtp1589127657-35 startFullFlush
[junit4] 2> 6669 T35 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6671 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: apply all deletes during flush
[junit4] 2> 6672 T35 C4 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: applyDeletes: no deletes; skipping
[junit4] 2> 6674 T35 C4 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: prune sis=org.apache.lucene.index.SegmentInfos@e6f3b520 minGen=13 packetCount=0
[junit4] 2> 6681 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: return reader version=7 reader=StandardDirectoryReader(segments_4:7:nrt _1(4.5):C10)
[junit4] 2> 6682 T35 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: qtp1589127657-35 finishFullFlush success=true
[junit4] 2> 6684 T35 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: getReader took 18 msec
[junit4] 2> 6686 T35 C4 oass.SolrIndexSearcher.<init> Opening Searcher@559b8c0b main
[junit4] 2> 6688 T35 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 6688 T37 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@559b8c0b main{StandardDirectoryReader(segments_4:7:nrt _1(4.5):C10)}
[junit4] 2> 6690 T37 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 6690 T37 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@559b8c0b main{StandardDirectoryReader(segments_4:7:nrt _1(4.5):C10)}
[junit4] 2> 6691 T35 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&commit=true&version=2&waitSearcher=true&wt=javabin} {commit=} 0 90
[junit4] 2> 6705 T33 C4 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&version=2&wt=javabin} hits=10 status=0 QTime=0
[junit4] 2> 6723 T32 C4 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&version=2&rows=0&stats.field=val_pi&wt=javabin&stats=true} hits=10 status=0 QTime=12
[junit4] 2> 6731 T28 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-28]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6732 T28 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-28]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 6733 T28 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-28]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6734 T28 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-28]: flush at getReader
[junit4] 2> 6735 T28 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-28]: qtp1589127657-28 startFullFlush
[junit4] 2> 6736 T28 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-28]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6737 T28 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-28]: qtp1589127657-28: flush naked frozen global deletes
[junit4] 2> 6737 T28 C4 oasu.LoggingInfoStream.message [BD][qtp1589127657-28]: push deletes 1 deleted queries bytesUsed=36 delGen=15 packetCount=1 totBytesUsed=36
[junit4] 2> 6738 T28 C4 oasu.LoggingInfoStream.message [DW][qtp1589127657-28]: flush: push buffered deletes: 1 deleted queries bytesUsed=36
[junit4] 2> 6739 T28 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-28]: apply all deletes during flush
[junit4] 2> 6741 T28 C4 oasu.LoggingInfoStream.message [BD][qtp1589127657-28]: applyDeletes: infos=[_1(4.5):C10] packetCount=1
[junit4] 2> 6744 T28 C4 oasu.LoggingInfoStream.message [BD][qtp1589127657-28]: seg=_1(4.5):C10 segGen=13 coalesced deletes=[CoalescedDeletes(termSets=1,queries=1)] newDelCount=10 100% deleted
[junit4] 2> 6746 T28 C4 oasu.LoggingInfoStream.message [BD][qtp1589127657-28]: applyDeletes took 5 msec
[junit4] 2> 6748 T28 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-28]: now checkpoint "_1(4.5):C10/10" [1 segments ; isCommit = false]
[junit4] 2> 6750 T28 C4 oasu.LoggingInfoStream.message [IFD][qtp1589127657-28]: 2 msec to checkpoint
[junit4] 2> 6752 T28 C4 oasu.LoggingInfoStream.message [IW][qtp1589127657-28]: drop 100% deleted segments: _1(4.5):C10/10
[junit4] 2> ASYNC NEW_CORE C5 name=collection1 org.apache.solr.core.SolrCore@ca5c276d
[junit4] 2> 6773 T28 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-28]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 6775 T28 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-28]: 2 msec to checkpoint
[junit4] 2> 6775 T28 C5 oasu.LoggingInfoStream.message [BD][qtp1589127657-28]: prune sis=org.apache.lucene.index.SegmentInfos@e6f3b520 minGen=9223372036854775807 packetCount=1
[junit4] 2> 6776 T28 C5 oasu.LoggingInfoStream.message [BD][qtp1589127657-28]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 6777 T28 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-28]: return reader version=9 reader=StandardDirectoryReader(segments_4:9:nrt)
[junit4] 2> 6777 T28 C5 oasu.LoggingInfoStream.message [DW][qtp1589127657-28]: qtp1589127657-28 finishFullFlush success=true
[junit4] 2> 6778 T28 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-28]: getReader took 44 msec
[junit4] 2> 6778 T28 C5 oass.SolrIndexSearcher.<init> Opening Searcher@5d7ec363 realtime
[junit4] 2> 6779 T28 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {deleteByQuery=*:* (-1444249869274316800)} 0 49
[junit4] 2> 6785 T33 C5 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 6786 T33 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-33]: commit: start
[junit4] 2> 6786 T33 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-33]: commit: enter lock
[junit4] 2> 6787 T33 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-33]: commit: now prepare
[junit4] 2> 6787 T33 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-33]: prepareCommit: flush
[junit4] 2> 6788 T33 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-33]: index before flush
[junit4] 2> 6789 T33 C5 oasu.LoggingInfoStream.message [DW][qtp1589127657-33]: qtp1589127657-33 startFullFlush
[junit4] 2> 6789 T33 C5 oasu.LoggingInfoStream.message [DW][qtp1589127657-33]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6790 T33 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-33]: apply all deletes during flush
[junit4] 2> 6791 T33 C5 oasu.LoggingInfoStream.message [BD][qtp1589127657-33]: prune sis=org.apache.lucene.index.SegmentInfos@e6f3b520 minGen=9223372036854775807 packetCount=0
[junit4] 2> 6792 T33 C5 oasu.LoggingInfoStream.message [DW][qtp1589127657-33]: qtp1589127657-33 finishFullFlush success=true
[junit4] 2> 6793 T33 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-33]: startCommit(): start
[junit4] 2> 6794 T33 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-33]: startCommit index= changeCount=12
[junit4] 2> 6794 T33 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-33]: done all syncs: []
[junit4] 2> 6795 T33 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-33]: commit: pendingCommit != null
[junit4] 2> 6796 T33 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-33]: commit: wrote segments file "segments_5"
[junit4] 2> 6797 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: now checkpoint "" [0 segments ; isCommit = true]
[junit4] 2> 6798 T33 C5 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b875d92a lockFactory=org.apache.lucene.store.NativeFSLockFactory@6404d098),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b875d92a lockFactory=org.apache.lucene.store.NativeFSLockFactory@6404d098),segFN=segments_5,generation=5}
[junit4] 2> 6799 T33 C5 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 6799 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: deleteCommits: now decRef commit "segments_4"
[junit4] 2> 6800 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: delete "_1.nvd"
[junit4] 2> 6801 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: unable to remove file "_1.nvd": java.io.IOException: MockDirectoryWrapper: file "_1.nvd" is still open: cannot delete; Will re-try later.
[junit4] 2> 6802 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: delete "_1.si"
[junit4] 2> 6803 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: delete "_1_Lucene41_0.pos"
[junit4] 2> 6804 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: unable to remove file "_1_Lucene41_0.pos": java.io.IOException: MockDirectoryWrapper: file "_1_Lucene41_0.pos" is still open: cannot delete; Will re-try later.
[junit4] 2> 6804 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: delete "segments_4"
[junit4] 2> 6805 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: delete "_1_Lucene41_0.doc"
[junit4] 2> 6806 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: 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> 6807 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: delete "_1_Lucene41_0.tim"
[junit4] 2> 6808 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: 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> 6808 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: delete "_1.nvm"
[junit4] 2> 6809 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: delete "_1.fnm"
[junit4] 2> 6810 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: delete "_1.fdt"
[junit4] 2> 6812 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: unable to remove file "_1.fdt": java.io.IOException: MockDirectoryWrapper: file "_1.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 6814 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: delete "_1_Lucene41_0.tip"
[junit4] 2> 6816 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: delete "_1.fdx"
[junit4] 2> 6818 T33 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-33]: 21 msec to checkpoint
[junit4] 2> 6820 T33 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-33]: commit: done
[junit4] 2> 6823 T33 C5 oasu.LoggingInfoStream.message [DW][qtp1589127657-33]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6825 T33 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-33]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
[junit4] 2> 6827 T33 C5 oasu.LoggingInfoStream.message [DW][qtp1589127657-33]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6829 T33 C5 oass.SolrIndexSearcher.<init> Opening Searcher@c1075a5 main
[junit4] 2> 6831 T33 C5 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 6831 T37 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@c1075a5 main{StandardDirectoryReader(segments_4:9:nrt)}
[junit4] 2> 6834 T37 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 6834 T37 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c1075a5 main{StandardDirectoryReader(segments_4:9:nrt)}
[junit4] 2> 6835 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete pending file _1.nvd
[junit4] 2> 6835 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete "_1.nvd"
[junit4] 2> 6836 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete pending file _1_Lucene41_0.pos
[junit4] 2> 6836 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete "_1_Lucene41_0.pos"
[junit4] 2> 6837 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete pending file _1_Lucene41_0.doc
[junit4] 2> 6837 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete "_1_Lucene41_0.doc"
[junit4] 2> 6838 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete pending file _1_Lucene41_0.tim
[junit4] 2> 6838 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete "_1_Lucene41_0.tim"
[junit4] 2> 6839 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete pending file _1.fdt
[junit4] 2> 6839 T37 oasu.LoggingInfoStream.message [IFD][searcherExecutor-4-thread-1]: delete "_1.fdt"
[junit4] 2> 6840 T33 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&commit=true&version=2&waitSearcher=true&wt=javabin} {commit=} 0 55
[junit4] 2> 6850 T32 C5 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&version=2&wt=javabin} hits=0 status=0 QTime=1
[junit4] 2> 6857 T28 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[doc10 (1444249869404340224)]} 0 2
[junit4] 2> 6863 T35 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[doc11 (1444249869411680256)]} 0 1
[junit4] 2> 6869 T32 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[doc12 (1444249869417971712)]} 0 1
[junit4] 2> 6879 T33 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[doc13 (1444249869427408896)]} 0 2
[junit4] 2> 6889 T28 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[doc14 (1444249869438943232)]} 0 1
[junit4] 2> 6897 T35 C5 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 6898 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: start
[junit4] 2> 6899 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: enter lock
[junit4] 2> 6900 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: now prepare
[junit4] 2> 6900 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: prepareCommit: flush
[junit4] 2> 6901 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: index before flush
[junit4] 2> 6902 T35 C5 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: qtp1589127657-35 startFullFlush
[junit4] 2> 6902 T35 C5 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: anyChanges? numDocsInRam=5 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6903 T35 C5 oasu.LoggingInfoStream.message [DWFC][qtp1589127657-35]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 4 deleted terms (unique count=4) bytesUsed=932, segment=_2, aborting=false, numDocsInRAM=5, deleteQueue=DWDQ: [ generation: 10 ]]
[junit4] 2> 6904 T35 C5 oasu.LoggingInfoStream.message [DWPT][qtp1589127657-35]: flush postings as segment _2 numDocs=5
[junit4] 2> 6925 T35 C5 oasu.LoggingInfoStream.message [DWPT][qtp1589127657-35]: new segment has 0 deleted docs
[junit4] 2> 6931 T35 C5 oasu.LoggingInfoStream.message [DWPT][qtp1589127657-35]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 6932 T35 C5 oasu.LoggingInfoStream.message [DWPT][qtp1589127657-35]: flushedFiles=[_2.nvd, _2_Lucene41_0.pos, _2_Lucene41_0.tim, _2_Lucene41_0.doc, _2_Lucene41_0.tip, _2.fnm, _2.nvm, _2.fdt, _2.fdx]
[junit4] 2> 6932 T35 C5 oasu.LoggingInfoStream.message [DWPT][qtp1589127657-35]: flushed codec=Lucene45
[junit4] 2> 6933 T35 C5 oasu.LoggingInfoStream.message [DWPT][qtp1589127657-35]: flushed: segment=_2 ramUsed=0.081 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=3,799.188
[junit4] 2> 6934 T35 C5 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 6935 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: publishFlushedSegment
[junit4] 2> 6936 T35 C5 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: push deletes 5 deleted terms (unique count=5) bytesUsed=1024 delGen=18 packetCount=1 totBytesUsed=1024
[junit4] 2> 6937 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: publish sets newSegment delGen=19 seg=_2(4.5):C5
[junit4] 2> 6938 T35 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: now checkpoint "_2(4.5):C5" [1 segments ; isCommit = false]
[junit4] 2> 6938 T35 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: 0 msec to checkpoint
[junit4] 2> 6939 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: apply all deletes during flush
[junit4] 2> 6940 T35 C5 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: applyDeletes: infos=[_2(4.5):C5] packetCount=1
[junit4] 2> 6941 T35 C5 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: applyDeletes took 1 msec
[junit4] 2> 6941 T35 C5 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: prune sis=org.apache.lucene.index.SegmentInfos@e6f3b520 minGen=20 packetCount=1
[junit4] 2> 6942 T35 C5 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 6943 T35 C5 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: qtp1589127657-35 finishFullFlush success=true
[junit4] 2> 6944 T35 C5 oasu.LoggingInfoStream.message [TMP][qtp1589127657-35]: findMerges: 1 segments
[junit4] 2> 6945 T35 C5 oasu.LoggingInfoStream.message [TMP][qtp1589127657-35]: seg=_2(4.5):C5 size=0.001 MB [floored]
[junit4] 2> 6945 T35 C5 oasu.LoggingInfoStream.message [TMP][qtp1589127657-35]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 6946 T35 C5 oasu.LoggingInfoStream.message [CMS][qtp1589127657-35]: now merge
[junit4] 2> 6949 T35 C5 oasu.LoggingInfoStream.message [CMS][qtp1589127657-35]: index: _2(4.5):C5
[junit4] 2> 6949 T35 C5 oasu.LoggingInfoStream.message [CMS][qtp1589127657-35]: no more merges pending; now return
[junit4] 2> 6950 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: startCommit(): start
[junit4] 2> 6951 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: startCommit index=_2(4.5):C5 changeCount=15
[junit4] 2> 6952 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: done all syncs: [_2.si, _2.nvd, _2_Lucene41_0.pos, _2_Lucene41_0.doc, _2_Lucene41_0.tim, _2_Lucene41_0.tip, _2.nvm, _2.fnm, _2.fdt, _2.fdx]
[junit4] 2> 6953 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: pendingCommit != null
[junit4] 2> 6954 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: wrote segments file "segments_6"
[junit4] 2> 6954 T35 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: now checkpoint "_2(4.5):C5" [1 segments ; isCommit = true]
[junit4] 2> 6955 T35 C5 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b875d92a lockFactory=org.apache.lucene.store.NativeFSLockFactory@6404d098),segFN=segments_5,generation=5}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b875d92a lockFactory=org.apache.lucene.store.NativeFSLockFactory@6404d098),segFN=segments_6,generation=6}
[junit4] 2> 6956 T35 C5 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
[junit4] 2> 6957 T35 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: deleteCommits: now decRef commit "segments_5"
[junit4] 2> 6957 T35 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: delete "segments_5"
[junit4] 2> 6958 T35 C5 oasu.LoggingInfoStream.message [IFD][qtp1589127657-35]: 4 msec to checkpoint
[junit4] 2> 6961 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: commit: done
[junit4] 2> 6964 T35 C5 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6967 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 6969 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: flush at getReader
[junit4] 2> 6972 T35 C5 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: qtp1589127657-35 startFullFlush
[junit4] 2> 6974 T35 C5 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 6975 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: apply all deletes during flush
[junit4] 2> 6993 T35 C5 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: applyDeletes: no deletes; skipping
[junit4] 2> 6996 T35 C5 oasu.LoggingInfoStream.message [BD][qtp1589127657-35]: prune sis=org.apache.lucene.index.SegmentInfos@e6f3b520 minGen=20 packetCount=0
[junit4] 2> 7005 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: return reader version=11 reader=StandardDirectoryReader(segments_6:11:nrt _2(4.5):C5)
[junit4] 2> 7007 T35 C5 oasu.LoggingInfoStream.message [DW][qtp1589127657-35]: qtp1589127657-35 finishFullFlush success=true
[junit4] 2> 7009 T35 C5 oasu.LoggingInfoStream.message [IW][qtp1589127657-35]: getReader took 40 msec
[junit4] 2> 7009 T35 C5 oass.SolrIndexSearcher.<init> Opening Searcher@5cdac237 main
[junit4] 2> 7011 T35 C5 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 7011 T37 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@5cdac237 main{StandardDirectoryReader(segments_6:11:nrt _2(4.5):C5)}
[junit4] 2> 7012 T37 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 7012 T37 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5cdac237 main{StandardDirectoryReader(segments_6:11:nrt _2(4.5):C5)}
[junit4] 2> 7016 T35 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&commit=true&version=2&waitSearcher=true&wt=javabin} {commit=} 0 119
[junit4] 2> 7023 T32 C5 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&version=2&wt=javabin} hits=5 status=0 QTime=1
[junit4] 2> 7030 T33 C5 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&version=2&rows=0&stats.field=val_pi&wt=javabin&stats=true} hits=5 status=0
[...truncated too long message...]
teProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&commit=true&version=2&waitSearcher=true&wt=javabin} {commit=} 0 45
[junit4] 2> 217143 T32 C30 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&fl=id,price,[docid],[explain+style%3Dnl],score,aaa:[value+v%3Daaa],ten:[value+v%3D10+t%3Dint]&version=2&wt=javabin&sort=price+asc} hits=2 status=0 QTime=2
[junit4] 2> 217145 T24 oas.SolrTestCaseJ4.tearDown ###Ending testAugmentFields
[junit4] 2> 217207 T24 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1276227018
[junit4] 2> 217208 T24 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@ca5c276d
[junit4] 2> 217208 T24 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=59,autocommit maxTime=15000ms,autocommits=1,soft autocommits=3,optimizes=2,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=1,cumulative_adds=149,cumulative_deletesById=5,cumulative_deletesByQuery=26,cumulative_errors=1}
[junit4] 2> 217209 T24 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 217209 T24 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 217210 T24 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 217210 T24 C30 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: now flush at close waitForMerges=true
[junit4] 2> 217211 T24 C30 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: start flush: applyAllDeletes=true
[junit4] 2> 217211 T24 C30 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: index before flush _12(4.5):C1 _13(4.5):C1
[junit4] 2> 217212 T24 C30 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker startFullFlush
[junit4] 2> 217212 T24 C30 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 217213 T24 C30 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker finishFullFlush success=true
[junit4] 2> 217213 T24 C30 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: apply all deletes during flush
[junit4] 2> 217213 T24 C30 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: applyDeletes: no deletes; skipping
[junit4] 2> 217214 T24 C30 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@e6f3b520 minGen=229 packetCount=0
[junit4] 2> 217214 T24 C30 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: now merge
[junit4] 2> 217215 T24 C30 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: index: _12(4.5):C1 _13(4.5):C1
[junit4] 2> 217215 T24 C30 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: no more merges pending; now return
[junit4] 2> 217215 T24 C30 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: waitForMerges
[junit4] 2> 217216 T24 C30 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: waitForMerges done
[junit4] 2> 217216 T24 C30 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: now call final commit()
[junit4] 2> 217217 T24 C30 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: commit: start
[junit4] 2> 217217 T24 C30 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: commit: enter lock
[junit4] 2> 217217 T24 C30 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: commit: now prepare
[junit4] 2> 217218 T24 C30 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: prepareCommit: flush
[junit4] 2> 217218 T24 C30 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: index before flush _12(4.5):C1 _13(4.5):C1
[junit4] 2> 217218 T24 C30 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker startFullFlush
[junit4] 2> 217219 T24 C30 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 217219 T24 C30 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: apply all deletes during flush
[junit4] 2> 217220 T24 C30 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: applyDeletes: no deletes; skipping
[junit4] 2> 217220 T24 C30 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@e6f3b520 minGen=229 packetCount=0
[junit4] 2> 217221 T24 C30 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker finishFullFlush success=true
[junit4] 2> 217221 T24 C30 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: startCommit(): start
[junit4] 2> 217222 T24 C30 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: skip startCommit(): no changes pending
[junit4] 2> 217222 T24 C30 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: commit: pendingCommit == null; skip
[junit4] 2> 217222 T24 C30 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: commit: done
[junit4] 2> 217223 T24 C30 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[E13110CCDB408442]-worker]: at close: _12(4.5):C1 _13(4.5):C1
[junit4] 2> 217224 T24 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 217224 T24 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 217225 T24 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleBinaryTest-1377344000441/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleBinaryTest-1377344000441/index;done=false>>]
[junit4] 2> 217226 T24 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleBinaryTest-1377344000441/index
[junit4] 2> 217226 T24 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleBinaryTest-1377344000441 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleBinaryTest-1377344000441;done=false>>]
[junit4] 2> 217226 T24 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleBinaryTest-1377344000441
[junit4] 2> 217227 T24 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 217281 T24 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Appending, sim=DefaultSimilarity, locale=sr_RS_#Latn, timezone=Australia/North
[junit4] 2> NOTE: Linux 3.2.0-52-generic amd64/IBM Corporation 1.7.0 (64-bit)/cpus=8,threads=2,free=9883224,total=37814272
[junit4] 2> NOTE: All tests run in this JVM: [SolrExampleBinaryTest]
[junit4] Completed on J1 in 217.43s, 26 tests, 1 error <<< FAILURES!
[...truncated 40 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:395: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:388: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:194: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:450: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1233: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:876: There were test failures: 46 suites, 272 tests, 1 error, 1 ignored
Total time: 35 minutes 13 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure