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/07 18:44:08 UTC
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 711 -
Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/711/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.client.solrj.SolrExampleBinaryTest.testStatistics
Error Message:
IOException occured when talking to server at: https://127.0.0.1:51553/solr/collection1
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:51553/solr/collection1
at __randomizedtesting.SeedInfo.seed([F7A8C6F50351DBCF:1F591AF7C0127]: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.add(SolrServer.java:116)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
at org.apache.solr.client.solrj.SolrExampleTests.testStatistics(SolrExampleTests.java:873)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Caused by: org.apache.http.NoHttpResponseException: The target server failed to respond
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:95)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:62)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:254)
at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:289)
at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:252)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:191)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:717)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:522)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
... 45 more
Build Log:
[...truncated 10610 lines...]
[junit4] Suite: org.apache.solr.client.solrj.SolrExampleBinaryTest
[junit4] 2> 66612 T74 oas.SolrTestCaseJ4.startTrackingSearchers WARN startTrackingSearchers: numOpens=12 numCloses=12
[junit4] 2> 66616 T74 oas.SolrJettyTestBase.beforeSolrJettyTestBase Randomized ssl (true) and clientAuth (false)
[junit4] 2> 66617 T74 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/./solrtest-SolrExampleBinaryTest-1375893333139
[junit4] 2> 66618 T74 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 66658 T74 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 67267 T74 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 67290 T74 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:51553
[junit4] 2> 67295 T74 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 67296 T74 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 67297 T74 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr
[junit4] 2> 67297 T74 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/'
[junit4] 2> 67400 T74 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/solr.xml
[junit4] 2> 67574 T74 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 67576 T74 oasc.CoreContainer.<init> New CoreContainer 544108999
[junit4] 2> 67576 T74 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/]
[junit4] 2> 67580 T74 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 67581 T74 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 67581 T74 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 67582 T74 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 67583 T74 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 67583 T74 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 67584 T74 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 67585 T74 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 67586 T74 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 67587 T74 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 67665 T74 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr
[junit4] 2> 67747 T74 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/
[junit4] 2> 67750 T74 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 67758 T84 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1
[junit4] 2> 67758 T84 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/'
[junit4] 2> 67865 T84 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 67867 T84 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/extraction/lib (resolved as: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/../../../contrib/extraction/lib).
[junit4] 2> 67868 T84 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/../../../dist).
[junit4] 2> 67869 T84 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/clustering/lib/ (resolved as: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/../../../contrib/clustering/lib).
[junit4] 2> 67870 T84 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/../../../dist).
[junit4] 2> 67871 T84 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/langid/lib/ (resolved as: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/../../../contrib/langid/lib).
[junit4] 2> 67872 T84 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/../../../dist).
[junit4] 2> 67873 T84 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/velocity/lib (resolved as: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/../../../contrib/velocity/lib).
[junit4] 2> 67873 T84 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/../../../dist).
[junit4] 2> 68035 T84 oasu.SolrIndexConfig.<init> IndexWriter infoStream solr logging is enabled
[junit4] 2> 68041 T84 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 68253 T84 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 68254 T84 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 68334 T84 oass.IndexSchema.readSchema [collection1] Schema name=example
[junit4] 2> 69739 T84 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 69799 T84 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 69810 T84 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 69901 T84 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 69901 T84 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleBinaryTest-1375893333139/
[junit4] 2> 69902 T84 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@56274057
[junit4] 2> 69906 T84 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4] 2> 69907 T84 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
[junit4] 2> 69908 T84 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleBinaryTest-1375893333139
[junit4] 2> 69908 T84 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleBinaryTest-1375893333139/index/
[junit4] 2> 69909 T84 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleBinaryTest-1375893333139/index' doesn't exist. Creating new index...
[junit4] 2> 69910 T84 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleBinaryTest-1375893333139/index
[junit4] 2> 69914 T84 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-60-thread-1]: init: current segments file is "null"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@77dadfb3
[junit4] 2> 69918 T84 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-60-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 69919 T84 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-60-thread-1]: 0 msec to checkpoint
[junit4] 2> 69919 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: init: create=true
[junit4] 2> 69920 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]:
[junit4] 2> dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4c53953f lockFactory=org.apache.lucene.store.NativeFSLockFactory@64d50ce7)
[junit4] 2> index=
[junit4] 2> version=5.0-SNAPSHOT
[junit4] 2> matchVersion=LUCENE_50
[junit4] 2> analyzer=null
[junit4] 2> ramBufferSizeMB=100.0
[junit4] 2> maxBufferedDocs=-1
[junit4] 2> maxBufferedDeleteTerms=-1
[junit4] 2> mergedSegmentWarmer=null
[junit4] 2> delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
[junit4] 2> commit=null
[junit4] 2> openMode=CREATE
[junit4] 2> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
[junit4] 2> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
[junit4] 2> default WRITE_LOCK_TIMEOUT=1000
[junit4] 2> writeLockTimeout=1000
[junit4] 2> codec=Lucene42
[junit4] 2> infoStream=org.apache.solr.update.LoggingInfoStream
[junit4] 2> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> indexerThreadPool=org.apache.lucene.index.ThreadAffinityDocumentsWriterThreadPool@42949e3e
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2>
[junit4] 2> 69921 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: now flush at close waitForMerges=true
[junit4] 2> 69921 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: start flush: applyAllDeletes=true
[junit4] 2> 69922 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: index before flush
[junit4] 2> 69923 T84 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-60-thread-1]: coreLoadExecutor-60-thread-1 startFullFlush
[junit4] 2> 69924 T84 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-60-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 69924 T84 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-60-thread-1]: coreLoadExecutor-60-thread-1 finishFullFlush success=true
[junit4] 2> 69925 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: apply all deletes during flush
[junit4] 2> 69925 T84 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-60-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@2b211a98 minGen=9223372036854775807 packetCount=0
[junit4] 2> 69926 T84 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-60-thread-1]: now merge
[junit4] 2> 69927 T84 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-60-thread-1]: index:
[junit4] 2> 69927 T84 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-60-thread-1]: no more merges pending; now return
[junit4] 2> 69928 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: waitForMerges
[junit4] 2> 69928 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: waitForMerges done
[junit4] 2> 69929 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: now call final commit()
[junit4] 2> 69929 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: commit: start
[junit4] 2> 69930 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: commit: enter lock
[junit4] 2> 69930 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: commit: now prepare
[junit4] 2> 69931 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: prepareCommit: flush
[junit4] 2> 69931 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: index before flush
[junit4] 2> 69932 T84 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-60-thread-1]: coreLoadExecutor-60-thread-1 startFullFlush
[junit4] 2> 69932 T84 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-60-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 69933 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: apply all deletes during flush
[junit4] 2> 69933 T84 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-60-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@2b211a98 minGen=9223372036854775807 packetCount=0
[junit4] 2> 69934 T84 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-60-thread-1]: coreLoadExecutor-60-thread-1 finishFullFlush success=true
[junit4] 2> 69934 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: startCommit(): start
[junit4] 2> 69935 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: startCommit index= changeCount=1
[junit4] 2> 69935 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: done all syncs: []
[junit4] 2> 69936 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: commit: pendingCommit != null
[junit4] 2> 69937 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: commit: wrote segments file "segments_1"
[junit4] 2> 69937 T84 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-60-thread-1]: now checkpoint "" [0 segments ; isCommit = true]
[junit4] 2> 69938 T84 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4c53953f lockFactory=org.apache.lucene.store.NativeFSLockFactory@64d50ce7),segFN=segments_1,generation=1}
[junit4] 2> 69939 T84 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 69939 T84 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-60-thread-1]: 1 msec to checkpoint
[junit4] 2> 69940 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: commit: done
[junit4] 2> 69940 T84 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-60-thread-1]: at close:
[junit4] 2> 69942 T84 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 69942 T84 oasc.SolrCore.initWriters adding lazy queryResponseWriter: solr.VelocityResponseWriter
[junit4] 2> 69943 T84 oasc.SolrCore.initWriters created velocity: solr.VelocityResponseWriter
[junit4] 2> 69943 T84 oasc.SolrCore.initWriters created xslt: solr.XSLTResponseWriter
[junit4] 2> 69944 T84 oasr.XSLTResponseWriter.init xsltCacheLifetimeSeconds=5
[junit4] 2> 69994 T84 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 69998 T84 oasc.RequestHandlers.initHandlersFromConfig created /query: solr.SearchHandler
[junit4] 2> 70001 T84 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 70003 T84 oasc.RequestHandlers.initHandlersFromConfig created /browse: solr.SearchHandler
[junit4] 2> 70005 T84 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 70006 T84 oasc.RequestHandlers.initHandlersFromConfig created /update/json: solr.JsonUpdateRequestHandler
[junit4] 2> 70008 T84 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: solr.CSVRequestHandler
[junit4] 2> 70008 T84 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
[junit4] 2> 70009 T84 oasc.RequestHandlers.initHandlersFromConfig created /update/extract: solr.extraction.ExtractingRequestHandler
[junit4] 2> 70010 T84 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.FieldAnalysisRequestHandler
[junit4] 2> 70010 T84 oasc.RequestHandlers.initHandlersFromConfig created /analysis/field: solr.FieldAnalysisRequestHandler
[junit4] 2> 70011 T84 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
[junit4] 2> 70012 T84 oasc.RequestHandlers.initHandlersFromConfig created /analysis/document: solr.DocumentAnalysisRequestHandler
[junit4] 2> 70013 T84 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 70014 T84 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
[junit4] 2> 70016 T84 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 70018 T84 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 70018 T84 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 70019 T84 oasc.RequestHandlers.initHandlersFromConfig created /spell: solr.SearchHandler
[junit4] 2> 70019 T84 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 70020 T84 oasc.RequestHandlers.initHandlersFromConfig created /tvrh: solr.SearchHandler
[junit4] 2> 70021 T84 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 70022 T84 oasc.RequestHandlers.initHandlersFromConfig created /terms: solr.SearchHandler
[junit4] 2> 70022 T84 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 70023 T84 oasc.RequestHandlers.initHandlersFromConfig created /elevate: solr.SearchHandler
[junit4] 2> 70039 T84 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 70042 T84 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 70044 T84 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 70065 T84 oass.SolrIndexSearcher.<init> Opening Searcher@5e044857 main
[junit4] 2> 70071 T84 oasu.CommitTracker.<init> Hard AutoCommit: if uncommited for 15000ms;
[junit4] 2> 70072 T84 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 70073 T84 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 70074 T84 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> 70075 T84 oashc.SpellCheckComponent.inform No queryConverter defined, using default converter
[junit4] 2> 70077 T84 oashc.QueryElevationComponent.inform Loading QueryElevation from: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/conf/elevate.xml
[junit4] 2> 70156 T84 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 70158 T85 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@5e044857 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> ASYNC NEW_CORE C12 name=collection1 org.apache.solr.core.SolrCore@3ed8e582
[junit4] 2> 70161 T85 C12 oasc.SolrCore.execute [collection1] webapp=null path=null params={event=firstSearcher&q=static+firstSearcher+warming+in+solrconfig.xml&distrib=false} hits=0 status=0 QTime=2
[junit4] 2> 70161 T85 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 70161 T85 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
[junit4] 2> 70162 T85 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
[junit4] 2> 70166 T85 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5e044857 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 70176 T84 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 70177 T74 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0
[junit4] 2> 70178 T74 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 70179 T74 oas.SolrJettyTestBase.createJetty Jetty Assigned Port#51553
[junit4] 2> 70206 T74 oas.SolrTestCaseJ4.setUp ###Starting testAddDelete
[junit4] 2> 70208 T74 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 70567 T80 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-80]: init: current segments file is "segments_1"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@77dadfb3
[junit4] 2> 70568 T80 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-80]: init: load commit "segments_1"
[junit4] 2> 70569 T80 C12 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4c53953f lockFactory=org.apache.lucene.store.NativeFSLockFactory@64d50ce7),segFN=segments_1,generation=1}
[junit4] 2> 70570 T80 C12 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 70571 T80 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-80]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 70572 T80 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-80]: 0 msec to checkpoint
[junit4] 2> 70572 T80 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-80]: init: create=false
[junit4] 2> 70573 T80 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-80]:
[junit4] 2> dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4c53953f lockFactory=org.apache.lucene.store.NativeFSLockFactory@64d50ce7)
[junit4] 2> index=
[junit4] 2> version=5.0-SNAPSHOT
[junit4] 2> matchVersion=LUCENE_50
[junit4] 2> analyzer=null
[junit4] 2> ramBufferSizeMB=100.0
[junit4] 2> maxBufferedDocs=-1
[junit4] 2> maxBufferedDeleteTerms=-1
[junit4] 2> mergedSegmentWarmer=null
[junit4] 2> delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
[junit4] 2> commit=null
[junit4] 2> openMode=APPEND
[junit4] 2> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
[junit4] 2> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
[junit4] 2> default WRITE_LOCK_TIMEOUT=1000
[junit4] 2> writeLockTimeout=1000
[junit4] 2> codec=Lucene42
[junit4] 2> infoStream=org.apache.solr.update.LoggingInfoStream
[junit4] 2> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> indexerThreadPool=org.apache.lucene.index.ThreadAffinityDocumentsWriterThreadPool@385cb66c
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2>
[junit4] 2> 70575 T80 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-80]: flush at getReader
[junit4] 2> 70577 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: qtp2021644142-80 startFullFlush
[junit4] 2> 70579 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 70582 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: qtp2021644142-80: flush naked frozen global deletes
[junit4] 2> 70583 T80 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-80]: push deletes 1 deleted queries bytesUsed=36 delGen=1 packetCount=1 totBytesUsed=36
[junit4] 2> 70584 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: flush: push buffered deletes: 1 deleted queries bytesUsed=36
[junit4] 2> 70585 T80 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-80]: apply all deletes during flush
[junit4] 2> 70586 T80 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-80]: prune sis=org.apache.lucene.index.SegmentInfos@23f8b8d6 minGen=9223372036854775807 packetCount=1
[junit4] 2> 70587 T80 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-80]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 70588 T80 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-80]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
[junit4] 2> 70589 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: qtp2021644142-80 finishFullFlush success=true
[junit4] 2> 70591 T80 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-80]: getReader took 16 msec
[junit4] 2> 70592 T80 C12 oass.SolrIndexSearcher.<init> Opening Searcher@1ea5c8f6 realtime
[junit4] 2> 70594 T80 C12 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1442728731827240960)} 0 31
[junit4] 2> 70609 T82 C12 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[0 & 222 (1442728731873378304)]} 0 2
[junit4] 2> 70624 T83 C12 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 70625 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: commit: start
[junit4] 2> 70625 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: commit: enter lock
[junit4] 2> 70626 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: commit: now prepare
[junit4] 2> 70626 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: prepareCommit: flush
[junit4] 2> 70627 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: index before flush
[junit4] 2> 70627 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: qtp2021644142-83 startFullFlush
[junit4] 2> 70628 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 70629 T83 C12 oasu.LoggingInfoStream.message [DWFC][qtp2021644142-83]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_0, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 1 ]]
[junit4] 2> 70630 T83 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-83]: flush postings as segment _0 numDocs=1
[junit4] 2> 70633 T83 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-83]: new segment has 0 deleted docs
[junit4] 2> 70634 T83 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-83]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 70635 T83 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-83]: flushedFiles=[_0.fnm, _0_Lucene41_0.doc, _0.fdx, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0.fdt]
[junit4] 2> 70635 T83 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-83]: flushed codec=Lucene42
[junit4] 2> 70639 T83 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-83]: flushed: segment=_0 ramUsed=0.063 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=1,804.778
[junit4] 2> 70640 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 70640 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: publishFlushedSegment
[junit4] 2> 70641 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=3 packetCount=1 totBytesUsed=1024
[junit4] 2> 70642 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: publish sets newSegment delGen=4 seg=_0(5.0):C1
[junit4] 2> 70642 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: now checkpoint "_0(5.0):C1" [1 segments ; isCommit = false]
[junit4] 2> 70643 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: 0 msec to checkpoint
[junit4] 2> 70644 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: apply all deletes during flush
[junit4] 2> 70645 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: applyDeletes: infos=[_0(5.0):C1] packetCount=1
[junit4] 2> 70646 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: applyDeletes took 1 msec
[junit4] 2> 70646 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: prune sis=org.apache.lucene.index.SegmentInfos@23f8b8d6 minGen=5 packetCount=1
[junit4] 2> 70647 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 70648 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: qtp2021644142-83 finishFullFlush success=true
[junit4] 2> 70650 T83 C12 oasu.LoggingInfoStream.message [TMP][qtp2021644142-83]: findMerges: 1 segments
[junit4] 2> 70652 T83 C12 oasu.LoggingInfoStream.message [TMP][qtp2021644142-83]: seg=_0(5.0):C1 size=0.000 MB [floored]
[junit4] 2> 70653 T83 C12 oasu.LoggingInfoStream.message [TMP][qtp2021644142-83]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 70654 T83 C12 oasu.LoggingInfoStream.message [CMS][qtp2021644142-83]: now merge
[junit4] 2> 70655 T83 C12 oasu.LoggingInfoStream.message [CMS][qtp2021644142-83]: index: _0(5.0):C1
[junit4] 2> 70656 T83 C12 oasu.LoggingInfoStream.message [CMS][qtp2021644142-83]: no more merges pending; now return
[junit4] 2> 70657 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: startCommit(): start
[junit4] 2> 70658 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: startCommit index=_0(5.0):C1 changeCount=3
[junit4] 2> 70659 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: done all syncs: [_0.fnm, _0_Lucene41_0.doc, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip]
[junit4] 2> 70660 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: commit: pendingCommit != null
[junit4] 2> 70662 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: commit: wrote segments file "segments_2"
[junit4] 2> 70663 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: now checkpoint "_0(5.0):C1" [1 segments ; isCommit = true]
[junit4] 2> 70664 T83 C12 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4c53953f lockFactory=org.apache.lucene.store.NativeFSLockFactory@64d50ce7),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4c53953f lockFactory=org.apache.lucene.store.NativeFSLockFactory@64d50ce7),segFN=segments_2,generation=2}
[junit4] 2> 70664 T83 C12 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 70665 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: deleteCommits: now decRef commit "segments_1"
[junit4] 2> 70665 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: delete "segments_1"
[junit4] 2> 70666 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: 3 msec to checkpoint
[junit4] 2> 70666 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: commit: done
[junit4] 2> 70668 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 70668 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 70669 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: flush at getReader
[junit4] 2> 70669 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: qtp2021644142-83 startFullFlush
[junit4] 2> 70670 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 70670 T83 C12 oasu.LoggingInfoStream.message [DWFC][qtp2021644142-83]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 2 ]]
[junit4] 2> 70671 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: apply all deletes during flush
[junit4] 2> 70672 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: applyDeletes: no deletes; skipping
[junit4] 2> 70672 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: prune sis=org.apache.lucene.index.SegmentInfos@23f8b8d6 minGen=5 packetCount=0
[junit4] 2> 70674 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: return reader version=3 reader=StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)
[junit4] 2> 70675 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: qtp2021644142-83 finishFullFlush success=true
[junit4] 2> 70675 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: getReader took 6 msec
[junit4] 2> 70676 T83 C12 oass.SolrIndexSearcher.<init> Opening Searcher@539a1a11 main
[junit4] 2> 70678 T83 C12 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 70679 T85 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@539a1a11 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4] 2> 70679 T85 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 70695 T85 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@539a1a11 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4] 2> 70698 T83 C12 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 75
[junit4] 2> 70709 T78 C12 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=1
[junit4] 2> 70724 T79 C12 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {delete=[0 & 222 (-1442728731995013120)]} 0 2
[junit4] 2> 70741 T80 C12 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 70742 T80 C12 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 70743 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 70755 T80 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-80]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 70756 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 70756 T80 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-80]: flush at getReader
[junit4] 2> 70757 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: qtp2021644142-80 startFullFlush
[junit4] 2> 70758 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 70758 T80 C12 oasu.LoggingInfoStream.message [DWFC][qtp2021644142-80]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 3 ]]
[junit4] 2> 70760 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: qtp2021644142-80: flush naked frozen global deletes
[junit4] 2> 70761 T80 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-80]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=7 packetCount=1 totBytesUsed=1024
[junit4] 2> 70762 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: flush: push buffered deletes: 1 deleted terms (unique count=1) bytesUsed=1024
[junit4] 2> 70762 T80 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-80]: apply all deletes during flush
[junit4] 2> 70763 T80 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-80]: applyDeletes: infos=[_0(5.0):C1] packetCount=1
[junit4] 2> 70765 T80 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-80]: seg=_0(5.0):C1 segGen=5 coalesced deletes=[CoalescedDeletes(termSets=1,queries=0)] newDelCount=1 100% deleted
[junit4] 2> 70766 T80 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-80]: applyDeletes took 3 msec
[junit4] 2> 70766 T80 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-80]: now checkpoint "_0(5.0):C1/1" [1 segments ; isCommit = false]
[junit4] 2> 70767 T80 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-80]: 0 msec to checkpoint
[junit4] 2> 70768 T80 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-80]: drop 100% deleted segments: _0(5.0):C1/1
[junit4] 2> 70768 T80 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-80]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 70769 T80 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-80]: 0 msec to checkpoint
[junit4] 2> 70770 T80 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-80]: prune sis=org.apache.lucene.index.SegmentInfos@23f8b8d6 minGen=9223372036854775807 packetCount=1
[junit4] 2> 70777 T80 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-80]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 70778 T80 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-80]: return reader version=5 reader=StandardDirectoryReader(segments_2:5:nrt)
[junit4] 2> 70778 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: qtp2021644142-80 finishFullFlush success=true
[junit4] 2> 70779 T80 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-80]: getReader took 23 msec
[junit4] 2> 70780 T80 C12 oass.SolrIndexSearcher.<init> Opening Searcher@1dc6979b main
[junit4] 2> 70781 T85 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1dc6979b main{StandardDirectoryReader(segments_2:5:nrt)}
[junit4] 2> 70781 T85 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 70789 T85 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1dc6979b main{StandardDirectoryReader(segments_2:5:nrt)}
[junit4] 2> 70804 T80 C12 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 70805 T80 C12 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 64
[junit4] 2> 70827 T81 C12 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=6
[junit4] 2> 70838 T82 C12 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[0 & 222 (1442728732113502208)]} 0 2
[junit4] 2> 70851 T83 C12 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 70852 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: commit: start
[junit4] 2> 70852 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: commit: enter lock
[junit4] 2> 70853 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: commit: now prepare
[junit4] 2> 70853 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: prepareCommit: flush
[junit4] 2> 70854 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: index before flush
[junit4] 2> 70855 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: qtp2021644142-83 startFullFlush
[junit4] 2> 70855 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 70856 T83 C12 oasu.LoggingInfoStream.message [DWFC][qtp2021644142-83]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_1, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 4 ]]
[junit4] 2> 70857 T83 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-83]: flush postings as segment _1 numDocs=1
[junit4] 2> 70860 T83 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-83]: new segment has 0 deleted docs
[junit4] 2> 70861 T83 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-83]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 70862 T83 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-83]: flushedFiles=[_1.fdx, _1_Lucene41_0.doc, _1.fdt, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _1.fnm]
[junit4] 2> 70862 T83 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-83]: flushed codec=Lucene42
[junit4] 2> 70863 T83 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-83]: flushed: segment=_1 ramUsed=0.063 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=1,804.778
[junit4] 2> 70864 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 70865 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: publishFlushedSegment
[junit4] 2> 70865 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=9 packetCount=1 totBytesUsed=1024
[junit4] 2> 70866 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: publish sets newSegment delGen=10 seg=_1(5.0):C1
[junit4] 2> 70867 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: now checkpoint "_1(5.0):C1" [1 segments ; isCommit = false]
[junit4] 2> 70867 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: 0 msec to checkpoint
[junit4] 2> 70869 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: apply all deletes during flush
[junit4] 2> 70869 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: applyDeletes: infos=[_1(5.0):C1] packetCount=1
[junit4] 2> 70870 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: applyDeletes took 1 msec
[junit4] 2> 70870 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: prune sis=org.apache.lucene.index.SegmentInfos@23f8b8d6 minGen=11 packetCount=1
[junit4] 2> 70871 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 70872 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: qtp2021644142-83 finishFullFlush success=true
[junit4] 2> 70872 T83 C12 oasu.LoggingInfoStream.message [TMP][qtp2021644142-83]: findMerges: 1 segments
[junit4] 2> 70873 T83 C12 oasu.LoggingInfoStream.message [TMP][qtp2021644142-83]: seg=_1(5.0):C1 size=0.000 MB [floored]
[junit4] 2> 70874 T83 C12 oasu.LoggingInfoStream.message [TMP][qtp2021644142-83]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 70874 T83 C12 oasu.LoggingInfoStream.message [CMS][qtp2021644142-83]: now merge
[junit4] 2> 70875 T83 C12 oasu.LoggingInfoStream.message [CMS][qtp2021644142-83]: index: _1(5.0):C1
[junit4] 2> 70876 T83 C12 oasu.LoggingInfoStream.message [CMS][qtp2021644142-83]: no more merges pending; now return
[junit4] 2> 70876 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: startCommit(): start
[junit4] 2> 70877 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: startCommit index=_1(5.0):C1 changeCount=8
[junit4] 2> 70878 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: done all syncs: [_1.fdx, _1_Lucene41_0.doc, _1.fdt, _1.si, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _1.fnm]
[junit4] 2> 70878 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: commit: pendingCommit != null
[junit4] 2> 70879 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: commit: wrote segments file "segments_3"
[junit4] 2> 70880 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: now checkpoint "_1(5.0):C1" [1 segments ; isCommit = true]
[junit4] 2> 70880 T83 C12 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4c53953f lockFactory=org.apache.lucene.store.NativeFSLockFactory@64d50ce7),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4c53953f lockFactory=org.apache.lucene.store.NativeFSLockFactory@64d50ce7),segFN=segments_3,generation=3}
[junit4] 2> 70881 T83 C12 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 70882 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: deleteCommits: now decRef commit "segments_2"
[junit4] 2> 70882 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: delete "_0.fnm"
[junit4] 2> 70883 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: delete "_0_Lucene41_0.doc"
[junit4] 2> 70883 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: delete "segments_2"
[junit4] 2> 70884 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: delete "_0.fdx"
[junit4] 2> 70885 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: delete "_0.si"
[junit4] 2> 70885 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: delete "_0_Lucene41_0.tim"
[junit4] 2> 70886 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: delete "_0.fdt"
[junit4] 2> 70887 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: delete "_0_Lucene41_0.tip"
[junit4] 2> 70887 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: 7 msec to checkpoint
[junit4] 2> 70888 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: commit: done
[junit4] 2> 70889 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 70889 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 70890 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: flush at getReader
[junit4] 2> 70890 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: qtp2021644142-83 startFullFlush
[junit4] 2> 70891 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 70892 T83 C12 oasu.LoggingInfoStream.message [DWFC][qtp2021644142-83]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 5 ]]
[junit4] 2> 70892 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: apply all deletes during flush
[junit4] 2> 70893 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: applyDeletes: no deletes; skipping
[junit4] 2> 70893 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: prune sis=org.apache.lucene.index.SegmentInfos@23f8b8d6 minGen=11 packetCount=0
[junit4] 2> 70901 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: return reader version=7 reader=StandardDirectoryReader(segments_3:7:nrt _1(5.0):C1)
[junit4] 2> 70901 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: qtp2021644142-83 finishFullFlush success=true
[junit4] 2> 70902 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: getReader took 12 msec
[junit4] 2> 70903 T83 C12 oass.SolrIndexSearcher.<init> Opening Searcher@9954b10 main
[junit4] 2> 70912 T83 C12 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 70917 T85 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@9954b10 main{StandardDirectoryReader(segments_3:7:nrt _1(5.0):C1)}
[junit4] 2> 70919 T85 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 70925 T85 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9954b10 main{StandardDirectoryReader(segments_3:7:nrt _1(5.0):C1)}
[junit4] 2> 70927 T83 C12 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 77
[junit4] 2> 70944 T78 C12 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=3
[junit4] 2> 70990 T79 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-79]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 70991 T79 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-79]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 70995 T79 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-79]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 70996 T79 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-79]: flush at getReader
[junit4] 2> 70997 T79 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-79]: qtp2021644142-79 startFullFlush
[junit4] 2> 70997 T79 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-79]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 70999 T79 C12 oasu.LoggingInfoStream.message [DWFC][qtp2021644142-79]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 6 ]]
[junit4] 2> 71008 T79 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-79]: qtp2021644142-79: flush naked frozen global deletes
[junit4] 2> 71009 T79 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-79]: push deletes 1 deleted queries bytesUsed=36 delGen=13 packetCount=1 totBytesUsed=36
[junit4] 2> 71010 T79 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-79]: flush: push buffered deletes: 1 deleted queries bytesUsed=36
[junit4] 2> 71012 T79 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-79]: apply all deletes during flush
[junit4] 2> 71013 T79 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-79]: applyDeletes: infos=[_1(5.0):C1] packetCount=1
[junit4] 2> 71015 T79 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-79]: seg=_1(5.0):C1 segGen=11 coalesced deletes=[CoalescedDeletes(termSets=1,queries=1)] newDelCount=1 100% deleted
[junit4] 2> 71016 T79 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-79]: applyDeletes took 3 msec
[junit4] 2> 71017 T79 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-79]: now checkpoint "_1(5.0):C1/1" [1 segments ; isCommit = false]
[junit4] 2> 71017 T79 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-79]: 0 msec to checkpoint
[junit4] 2> 71018 T79 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-79]: drop 100% deleted segments: _1(5.0):C1/1
[junit4] 2> 71019 T79 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-79]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 71020 T79 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-79]: 1 msec to checkpoint
[junit4] 2> 71020 T79 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-79]: prune sis=org.apache.lucene.index.SegmentInfos@23f8b8d6 minGen=9223372036854775807 packetCount=1
[junit4] 2> 71021 T79 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-79]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 71021 T79 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-79]: return reader version=9 reader=StandardDirectoryReader(segments_3:9:nrt)
[junit4] 2> 71022 T79 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-79]: qtp2021644142-79 finishFullFlush success=true
[junit4] 2> 71022 T79 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-79]: getReader took 26 msec
[junit4] 2> 71023 T79 C12 oass.SolrIndexSearcher.<init> Opening Searcher@118d1895 realtime
[junit4] 2> 71024 T79 C12 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=id:"0\ \&\ 222" (-1442728732271837184)} 0 37
[junit4] 2> 71030 T81 C12 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 71030 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: commit: start
[junit4] 2> 71031 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: commit: enter lock
[junit4] 2> 71031 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: commit: now prepare
[junit4] 2> 71031 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: prepareCommit: flush
[junit4] 2> 71032 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: index before flush
[junit4] 2> 71032 T81 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-81]: qtp2021644142-81 startFullFlush
[junit4] 2> 71032 T81 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-81]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71033 T81 C12 oasu.LoggingInfoStream.message [DWFC][qtp2021644142-81]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 7 ]]
[junit4] 2> 71033 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: apply all deletes during flush
[junit4] 2> 71033 T81 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-81]: prune sis=org.apache.lucene.index.SegmentInfos@23f8b8d6 minGen=9223372036854775807 packetCount=0
[junit4] 2> 71034 T81 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-81]: qtp2021644142-81 finishFullFlush success=true
[junit4] 2> 71034 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: startCommit(): start
[junit4] 2> 71035 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: startCommit index= changeCount=11
[junit4] 2> 71035 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: done all syncs: []
[junit4] 2> 71035 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: commit: pendingCommit != null
[junit4] 2> 71037 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: commit: wrote segments file "segments_4"
[junit4] 2> 71037 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: now checkpoint "" [0 segments ; isCommit = true]
[junit4] 2> 71038 T81 C12 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4c53953f lockFactory=org.apache.lucene.store.NativeFSLockFactory@64d50ce7),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4c53953f lockFactory=org.apache.lucene.store.NativeFSLockFactory@64d50ce7),segFN=segments_4,generation=4}
[junit4] 2> 71038 T81 C12 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 71039 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: deleteCommits: now decRef commit "segments_3"
[junit4] 2> 71039 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: delete "_1.fdx"
[junit4] 2> 71040 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: delete "_1_Lucene41_0.doc"
[junit4] 2> 71040 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: 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> 71040 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: delete "_1.fdt"
[junit4] 2> 71041 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: unable to remove file "_1.fdt": java.io.IOException: MockDirectoryWrapper: file "_1.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 71041 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: delete "_1.si"
[junit4] 2> 71042 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: delete "_1_Lucene41_0.tim"
[junit4] 2> 71042 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: 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> 71043 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: delete "_1_Lucene41_0.tip"
[junit4] 2> 71044 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: delete "_1.fnm"
[junit4] 2> 71044 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: delete "segments_3"
[junit4] 2> 71045 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: 7 msec to checkpoint
[junit4] 2> 71045 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: commit: done
[junit4] 2> 71046 T81 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-81]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71047 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
[junit4] 2> 71047 T81 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-81]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71048 T81 C12 oass.SolrIndexSearcher.<init> Opening Searcher@29b2c6c5 main
[junit4] 2> 71049 T85 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@29b2c6c5 main{StandardDirectoryReader(segments_3:9:nrt)}
[junit4] 2> 71049 T85 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 71056 T85 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@29b2c6c5 main{StandardDirectoryReader(segments_3:9:nrt)}
[junit4] 2> 71058 T85 oasu.LoggingInfoStream.message [IFD][searcherExecutor-61-thread-1]: delete pending file _1_Lucene41_0.doc
[junit4] 2> 71058 T85 oasu.LoggingInfoStream.message [IFD][searcherExecutor-61-thread-1]: delete "_1_Lucene41_0.doc"
[junit4] 2> 71059 T85 oasu.LoggingInfoStream.message [IFD][searcherExecutor-61-thread-1]: delete pending file _1.fdt
[junit4] 2> 71073 T85 oasu.LoggingInfoStream.message [IFD][searcherExecutor-61-thread-1]: delete "_1.fdt"
[junit4] 2> 71073 T85 oasu.LoggingInfoStream.message [IFD][searcherExecutor-61-thread-1]: delete pending file _1_Lucene41_0.tim
[junit4] 2> 71074 T85 oasu.LoggingInfoStream.message [IFD][searcherExecutor-61-thread-1]: delete "_1_Lucene41_0.tim"
[junit4] 2> 71083 T81 C12 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 71084 T81 C12 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 54
[junit4] 2> 71092 T82 C12 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 71153 T83 C12 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[0 & 222 (1442728732392423424)]} 0 51
[junit4] 2> 71196 T79 C12 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1 & 222 (1442728732487843840)]} 0 3
[junit4] 2> 71216 T80 C12 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[2 & 222 (1442728732511961088)]} 0 1
[junit4] 2> 71263 T81 C12 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 71264 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: commit: start
[junit4] 2> 71265 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: commit: enter lock
[junit4] 2> 71265 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: commit: now prepare
[junit4] 2> 71266 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: prepareCommit: flush
[junit4] 2> 71267 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: index before flush
[junit4] 2> 71271 T81 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-81]: qtp2021644142-81 startFullFlush
[junit4] 2> 71271 T81 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-81]: anyChanges? numDocsInRam=3 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71272 T81 C12 oasu.LoggingInfoStream.message [DWFC][qtp2021644142-81]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 2 deleted terms (unique count=2) bytesUsed=470, segment=_2, aborting=false, numDocsInRAM=3, deleteQueue=DWDQ: [ generation: 8 ]]
[junit4] 2> 71273 T81 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-81]: flush postings as segment _2 numDocs=3
[junit4] 2> 71293 T81 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-81]: new segment has 0 deleted docs
[junit4] 2> 71294 T81 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-81]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 71295 T81 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-81]: flushedFiles=[_2_Lucene41_0.tim, _2.fdt, _2_Lucene41_0.doc, _2_Lucene41_0.tip, _2.fdx, _2.fnm]
[junit4] 2> 71296 T81 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-81]: flushed codec=Lucene42
[junit4] 2> 71297 T81 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-81]: flushed: segment=_2 ramUsed=0.063 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=4,832.147
[junit4] 2> 71298 T81 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-81]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 71298 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: publishFlushedSegment
[junit4] 2> 71299 T81 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-81]: push deletes 3 deleted terms (unique count=3) bytesUsed=1024 delGen=16 packetCount=1 totBytesUsed=1024
[junit4] 2> 71300 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: publish sets newSegment delGen=17 seg=_2(5.0):C3
[junit4] 2> 71300 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: now checkpoint "_2(5.0):C3" [1 segments ; isCommit = false]
[junit4] 2> 71301 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: 0 msec to checkpoint
[junit4] 2> 71301 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: apply all deletes during flush
[junit4] 2> 71302 T81 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-81]: applyDeletes: infos=[_2(5.0):C3] packetCount=1
[junit4] 2> 71303 T81 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-81]: applyDeletes took 1 msec
[junit4] 2> 71303 T81 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-81]: prune sis=org.apache.lucene.index.SegmentInfos@23f8b8d6 minGen=18 packetCount=1
[junit4] 2> 71304 T81 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-81]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 71305 T81 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-81]: qtp2021644142-81 finishFullFlush success=true
[junit4] 2> 71305 T81 C12 oasu.LoggingInfoStream.message [TMP][qtp2021644142-81]: findMerges: 1 segments
[junit4] 2> 71337 T81 C12 oasu.LoggingInfoStream.message [TMP][qtp2021644142-81]: seg=_2(5.0):C3 size=0.000 MB [floored]
[junit4] 2> 71343 T81 C12 oasu.LoggingInfoStream.message [TMP][qtp2021644142-81]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 71344 T81 C12 oasu.LoggingInfoStream.message [CMS][qtp2021644142-81]: now merge
[junit4] 2> 71345 T81 C12 oasu.LoggingInfoStream.message [CMS][qtp2021644142-81]: index: _2(5.0):C3
[junit4] 2> 71346 T81 C12 oasu.LoggingInfoStream.message [CMS][qtp2021644142-81]: no more merges pending; now return
[junit4] 2> 71346 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: startCommit(): start
[junit4] 2> 71347 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: startCommit index=_2(5.0):C3 changeCount=14
[junit4] 2> 71348 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: done all syncs: [_2.si, _2_Lucene41_0.tim, _2.fdt, _2_Lucene41_0.doc, _2_Lucene41_0.tip, _2.fdx, _2.fnm]
[junit4] 2> 71348 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: commit: pendingCommit != null
[junit4] 2> 71349 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: commit: wrote segments file "segments_5"
[junit4] 2> 71350 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: now checkpoint "_2(5.0):C3" [1 segments ; isCommit = true]
[junit4] 2> 71350 T81 C12 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4c53953f lockFactory=org.apache.lucene.store.NativeFSLockFactory@64d50ce7),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4c53953f lockFactory=org.apache.lucene.store.NativeFSLockFactory@64d50ce7),segFN=segments_5,generation=5}
[junit4] 2> 71354 T81 C12 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 71355 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: deleteCommits: now decRef commit "segments_4"
[junit4] 2> 71357 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: delete "segments_4"
[junit4] 2> 71358 T81 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-81]: 7 msec to checkpoint
[junit4] 2> 71358 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: commit: done
[junit4] 2> 71359 T81 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-81]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71360 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 71361 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: flush at getReader
[junit4] 2> 71361 T81 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-81]: qtp2021644142-81 startFullFlush
[junit4] 2> 71362 T81 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-81]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71362 T81 C12 oasu.LoggingInfoStream.message [DWFC][qtp2021644142-81]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 9 ]]
[junit4] 2> 71363 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: apply all deletes during flush
[junit4] 2> 71364 T81 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-81]: applyDeletes: no deletes; skipping
[junit4] 2> 71365 T81 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-81]: prune sis=org.apache.lucene.index.SegmentInfos@23f8b8d6 minGen=18 packetCount=0
[junit4] 2> 71367 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: return reader version=11 reader=StandardDirectoryReader(segments_5:11:nrt _2(5.0):C3)
[junit4] 2> 71367 T81 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-81]: qtp2021644142-81 finishFullFlush success=true
[junit4] 2> 71368 T81 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-81]: getReader took 7 msec
[junit4] 2> 71368 T81 C12 oass.SolrIndexSearcher.<init> Opening Searcher@254d2fba main
[junit4] 2> 71370 T81 C12 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 71375 T85 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@254d2fba main{StandardDirectoryReader(segments_5:11:nrt _2(5.0):C3)}
[junit4] 2> 71376 T85 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 71382 T85 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@254d2fba main{StandardDirectoryReader(segments_5:11:nrt _2(5.0):C3)}
[junit4] 2> 71394 T81 C12 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 131
[junit4] 2> 71412 T83 C12 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=3 status=0 QTime=1
[junit4] 2> 71467 T78 C12 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {delete=[0 & 222 (-1442728732748939264), 1 & 222 (-1442728732754182144), 2 & 222 (-1442728732774105088)]} 0 25
[junit4] 2> 71478 T80 C12 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 71479 T80 C12 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 71484 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71485 T80 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-80]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 71486 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71487 T80 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-80]: flush at getReader
[junit4] 2> 71488 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: qtp2021644142-80 startFullFlush
[junit4] 2> 71489 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71491 T80 C12 oasu.LoggingInfoStream.message [DWFC][qtp2021644142-80]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 10 ]]
[junit4] 2> 71492 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: qtp2021644142-80: flush naked frozen global deletes
[junit4] 2> 71493 T80 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-80]: push deletes 3 deleted terms (unique count=3) bytesUsed=1024 delGen=20 packetCount=1 totBytesUsed=1024
[junit4] 2> 71495 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: flush: push buffered deletes: 3 deleted terms (unique count=3) bytesUsed=1024
[junit4] 2> 71496 T80 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-80]: apply all deletes during flush
[junit4] 2> 71501 T80 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-80]: applyDeletes: infos=[_2(5.0):C3] packetCount=1
[junit4] 2> 71507 T80 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-80]: seg=_2(5.0):C3 segGen=18 coalesced deletes=[CoalescedDeletes(termSets=1,queries=0)] newDelCount=3 100% deleted
[junit4] 2> 71509 T80 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-80]: applyDeletes took 9 msec
[junit4] 2> 71510 T80 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-80]: now checkpoint "_2(5.0):C3/3" [1 segments ; isCommit = false]
[junit4] 2> 71511 T80 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-80]: 1 msec to checkpoint
[junit4] 2> 71512 T80 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-80]: drop 100% deleted segments: _2(5.0):C3/3
[junit4] 2> 71514 T80 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-80]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 71515 T80 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-80]: 1 msec to checkpoint
[junit4] 2> 71516 T80 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-80]: prune sis=org.apache.lucene.index.SegmentInfos@23f8b8d6 minGen=9223372036854775807 packetCount=1
[junit4] 2> 71522 T80 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-80]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 71523 T80 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-80]: return reader version=13 reader=StandardDirectoryReader(segments_5:13:nrt)
[junit4] 2> 71524 T80 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-80]: qtp2021644142-80 finishFullFlush success=true
[junit4] 2> 71524 T80 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-80]: getReader took 37 msec
[junit4] 2> 71525 T80 C12 oass.SolrIndexSearcher.<init> Opening Searcher@15fcadd1 main
[junit4] 2> 71526 T85 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@15fcadd1 main{StandardDirectoryReader(segments_5:13:nrt)}
[junit4] 2> 71527 T85 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 71539 T85 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@15fcadd1 main{StandardDirectoryReader(segments_5:13:nrt)}
[junit4] 2> 71560 T80 C12 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 71561 T80 C12 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 83
[junit4] 2> 71586 T81 C12 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=7
[junit4] 2> 71589 T74 oas.SolrTestCaseJ4.tearDown ###Ending testAddDelete
[junit4] 2> 71613 T74 oas.SolrTestCaseJ4.setUp ###Starting testUpdateMultiValuedField
[junit4] 2> 71640 T82 C12 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[123 (1442728732953411584)]} 0 3
[junit4] 2> 71648 T83 C12 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 71649 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: commit: start
[junit4] 2> 71649 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: commit: enter lock
[junit4] 2> 71650 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: commit: now prepare
[junit4] 2> 71651 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: prepareCommit: flush
[junit4] 2> 71651 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: index before flush
[junit4] 2> 71652 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: qtp2021644142-83 startFullFlush
[junit4] 2> 71653 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 71653 T83 C12 oasu.LoggingInfoStream.message [DWFC][qtp2021644142-83]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_3, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 11 ]]
[junit4] 2> 71654 T83 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-83]: flush postings as segment _3 numDocs=1
[junit4] 2> 71657 T83 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-83]: new segment has 0 deleted docs
[junit4] 2> 71657 T83 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-83]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 71658 T83 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-83]: flushedFiles=[_3.fdx, _3_Lucene41_0.doc, _3_Lucene41_0.tip, _3.fnm, _3_Lucene41_0.tim, _3.fdt]
[junit4] 2> 71658 T83 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-83]: flushed codec=Lucene42
[junit4] 2> 71659 T83 C12 oasu.LoggingInfoStream.message [DWPT][qtp2021644142-83]: flushed: segment=_3 ramUsed=0.063 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=1,833.175
[junit4] 2> 71660 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 71660 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: publishFlushedSegment
[junit4] 2> 71661 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=22 packetCount=1 totBytesUsed=1024
[junit4] 2> 71662 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: publish sets newSegment delGen=23 seg=_3(5.0):C1
[junit4] 2> 71662 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: now checkpoint "_3(5.0):C1" [1 segments ; isCommit = false]
[junit4] 2> 71663 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: 0 msec to checkpoint
[junit4] 2> 71664 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: apply all deletes during flush
[junit4] 2> 71664 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: applyDeletes: infos=[_3(5.0):C1] packetCount=1
[junit4] 2> 71665 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: applyDeletes took 1 msec
[junit4] 2> 71665 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: prune sis=org.apache.lucene.index.SegmentInfos@23f8b8d6 minGen=24 packetCount=1
[junit4] 2> 71666 T83 C12 oasu.LoggingInfoStream.message [BD][qtp2021644142-83]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 71667 T83 C12 oasu.LoggingInfoStream.message [DW][qtp2021644142-83]: qtp2021644142-83 finishFullFlush success=true
[junit4] 2> 71667 T83 C12 oasu.LoggingInfoStream.message [TMP][qtp2021644142-83]: findMerges: 1 segments
[junit4] 2> 71667 T83 C12 oasu.LoggingInfoStream.message [TMP][qtp2021644142-83]: seg=_3(5.0):C1 size=0.000 MB [floored]
[junit4] 2> 71668 T83 C12 oasu.LoggingInfoStream.message [TMP][qtp2021644142-83]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 71668 T83 C12 oasu.LoggingInfoStream.message [CMS][qtp2021644142-83]: now merge
[junit4] 2> 71668 T83 C12 oasu.LoggingInfoStream.message [CMS][qtp2021644142-83]: index: _3(5.0):C1
[junit4] 2> 71669 T83 C12 oasu.LoggingInfoStream.message [CMS][qtp2021644142-83]: no more merges pending; now return
[junit4] 2> 71669 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: startCommit(): start
[junit4] 2> 71670 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: startCommit index=_3(5.0):C1 changeCount=19
[junit4] 2> 71670 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: done all syncs: [_3.fdx, _3_Lucene41_0.doc, _3_Lucene41_0.tip, _3.si, _3.fdt, _3_Lucene41_0.tim, _3.fnm]
[junit4] 2> 71671 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: commit: pendingCommit != null
[junit4] 2> 71671 T83 C12 oasu.LoggingInfoStream.message [IW][qtp2021644142-83]: commit: wrote segments file "segments_6"
[junit4] 2> 71672 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: now checkpoint "_3(5.0):C1" [1 segments ; isCommit = true]
[junit4] 2> 71672 T83 C12 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4c53953f lockFactory=org.apache.lucene.store.NativeFSLockFactory@64d50ce7),segFN=segments_5,generation=5}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4c53953f lockFactory=org.apache.lucene.store.NativeFSLockFactory@64d50ce7),segFN=segments_6,generation=6}
[junit4] 2> 71672 T83 C12 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
[junit4] 2> 71673 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: deleteCommits: now decRef commit "segments_5"
[junit4] 2> 71673 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: delete "_2.si"
[junit4] 2> 71674 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: delete "_2_Lucene41_0.tim"
[junit4] 2> 71674 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: delete "_2.fdt"
[junit4] 2> 71675 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: delete "_2_Lucene41_0.doc"
[junit4] 2> 71675 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]: delete "_2_Lucene41_0.tip"
[junit4] 2> 71675 T83 C12 oasu.LoggingInfoStream.message [IFD][qtp2021644142-83]:
[...truncated too long message...]
ore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@3ed8e582
[junit4] 2> 290148 T74 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=60,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=141,cumulative_deletesById=5,cumulative_deletesByQuery=28,cumulative_errors=1}
[junit4] 2> 290151 T74 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 290153 T74 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 290166 T74 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 290181 T74 C13 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: now flush at close waitForMerges=true
[junit4] 2> 290182 T74 C13 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: start flush: applyAllDeletes=true
[junit4] 2> 290183 T74 C13 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: index before flush _16(5.0):C2
[junit4] 2> 290188 T74 C13 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker startFullFlush
[junit4] 2> 290190 T74 C13 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 290191 T74 C13 oasu.LoggingInfoStream.message [DWFC][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 130 ]]
[junit4] 2> 290192 T74 C13 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker finishFullFlush success=true
[junit4] 2> 290193 T74 C13 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: apply all deletes during flush
[junit4] 2> 290194 T74 C13 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: applyDeletes: no deletes; skipping
[junit4] 2> 290194 T74 C13 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@23f8b8d6 minGen=240 packetCount=0
[junit4] 2> 290195 T74 C13 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: now merge
[junit4] 2> 290196 T74 C13 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: index: _16(5.0):C2
[junit4] 2> 290196 T74 C13 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: no more merges pending; now return
[junit4] 2> 290197 T74 C13 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: waitForMerges
[junit4] 2> 290199 T74 C13 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: waitForMerges done
[junit4] 2> 290200 T74 C13 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: now call final commit()
[junit4] 2> 290201 T74 C13 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: commit: start
[junit4] 2> 290202 T74 C13 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: commit: enter lock
[junit4] 2> 290203 T74 C13 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: commit: now prepare
[junit4] 2> 290203 T74 C13 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: prepareCommit: flush
[junit4] 2> 290204 T74 C13 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: index before flush _16(5.0):C2
[junit4] 2> 290205 T74 C13 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker startFullFlush
[junit4] 2> 290205 T74 C13 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 290207 T74 C13 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: apply all deletes during flush
[junit4] 2> 290225 T74 C13 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: applyDeletes: no deletes; skipping
[junit4] 2> 290227 T74 C13 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@23f8b8d6 minGen=240 packetCount=0
[junit4] 2> 290229 T74 C13 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker finishFullFlush success=true
[junit4] 2> 290232 T74 C13 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: startCommit(): start
[junit4] 2> 290236 T74 C13 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: skip startCommit(): no changes pending
[junit4] 2> 290237 T74 C13 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: commit: pendingCommit == null; skip
[junit4] 2> 290238 T74 C13 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: commit: done
[junit4] 2> 290238 T74 C13 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleBinaryTest-seed#[F7A8C6F50351DBCF]-worker]: at close: _16(5.0):C2
[junit4] 2> 290245 T74 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 290246 T74 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 290247 T74 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleBinaryTest-1375893333139 [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleBinaryTest-1375893333139;done=false>>]
[junit4] 2> 290248 T74 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleBinaryTest-1375893333139
[junit4] 2> 290249 T74 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleBinaryTest-1375893333139/index [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleBinaryTest-1375893333139/index;done=false>>]
[junit4] 2> 290249 T74 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/solrtest-SolrExampleBinaryTest-1375893333139/index
[junit4] 2> 290251 T74 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 290308 T74 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=fr_BE, timezone=Etc/GMT-7
[junit4] 2> NOTE: Mac OS X 10.8.4 x86_64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=2,threads=1,free=33966584,total=216596480
[junit4] 2> NOTE: All tests run in this JVM: [TestBatchUpdate, NamedListTest, MultiCoreEmbeddedTest, TermsResponseTest, AnlysisResponseBaseTest, SolrPingTest, DocumentAnalysisResponseTest, QueryResponseTest, SolrQueryTest, TestSolrProperties, SolrExceptionTest, TestUpdateRequestCodec, TestHash, SolrExampleBinaryTest]
[junit4] Completed in 223.85s, 26 tests, 1 error <<< FAILURES!
[...truncated 102 lines...]
BUILD FAILED
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:389: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:369: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:194: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:449: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1230: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:873: There were test failures: 46 suites, 272 tests, 1 error
Total time: 115 minutes 52 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 712 -
Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/712/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseG1GC
1 tests failed.
REGRESSION: org.apache.solr.core.OpenCloseCoreStressTest.test30SecondsNew
Error Message:
Core 00000_core bad! expected:<577> but was:<0>
Stack Trace:
java.lang.AssertionError: Core 00000_core bad! expected:<577> but was:<0>
at __randomizedtesting.SeedInfo.seed([F4F018FC62AFA912:90450428306F5057]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.core.OpenCloseCoreStressTest.checkResults(OpenCloseCoreStressTest.java:307)
at org.apache.solr.core.OpenCloseCoreStressTest.doStress(OpenCloseCoreStressTest.java:201)
at org.apache.solr.core.OpenCloseCoreStressTest.test30SecondsNew(OpenCloseCoreStressTest.java:121)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 9750 lines...]
[junit4] Suite: org.apache.solr.core.OpenCloseCoreStressTest
[junit4] 2> 3482434 T5133 oas.SolrTestCaseJ4.setUp ###Starting test30SecondsOld
[junit4] 2> 3482693 T5133 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 3482700 T5133 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50532
[junit4] 2> 3482702 T5133 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 3482702 T5133 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 3482703 T5133 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_
[junit4] 2> 3482703 T5133 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/'
[junit4] 2> 3482754 T5133 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/solr.xml
[junit4] 2> 3482932 T5133 oasc.CoreContainer.<init> New CoreContainer 1993377773
[junit4] 2> 3482933 T5133 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/]
[junit4] 2> 3482936 T5133 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 3482937 T5133 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 3482938 T5133 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 3482938 T5133 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 3482939 T5133 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 3482939 T5133 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 3482940 T5133 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 3482940 T5133 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 3482941 T5133 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 3482942 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 3483027 T5143 oasc.CoreContainer.create Creating SolrCore '00000_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00000_core
[junit4] 2> 3483028 T5143 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00000_core/'
[junit4] 2> 3483130 T5143 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4] 2> 3483230 T5143 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-minimal.xml
[junit4] 2> 3483231 T5143 oass.IndexSchema.readSchema Reading Solr Schema from schema-tiny.xml
[junit4] 2> 3483240 T5143 oass.IndexSchema.readSchema [00000_core] Schema name=tiny
[junit4] 2> 3483289 T5143 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3483291 T5143 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockFSDirectoryFactory
[junit4] 2> 3483292 T5143 oasc.SolrCore.<init> [00000_core] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00000_core/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00000_core/data/
[junit4] 2> 3483292 T5143 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6feeae6
[junit4] 2> 3483294 T5143 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00000_core/data
[junit4] 2> 3483295 T5143 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00000_core/data/index/
[junit4] 2> 3483296 T5143 oasc.SolrCore.initIndex WARN [00000_core] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00000_core/data/index' doesn't exist. Creating new index...
[junit4] 2> 3483296 T5143 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00000_core/data/index
[junit4] 2> 3483302 T5143 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00000_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6b926d6d),segFN=segments_1,generation=1}
[junit4] 2> 3483303 T5143 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3483305 T5143 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 3483312 T5143 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 3483314 T5143 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 3483314 T5143 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3483338 T5143 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3483345 T5143 oass.SolrIndexSearcher.<init> Opening Searcher@5bc1fc34 main
[junit4] 2> 3483348 T5143 oasc.SolrCore.registerSearcher [00000_core] Registered new searcher Searcher@5bc1fc34 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 3483349 T5143 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3483349 T5143 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 3483361 T5143 oasc.CoreContainer.registerCore registering core: 00000_core
[junit4] 2> 3483363 T5133 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 3483364 T5133 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 3483366 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483390 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483425 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483448 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483472 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483497 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483530 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483551 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483568 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483590 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483610 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483626 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483650 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483668 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483687 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483710 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483739 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483762 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483779 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483795 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483809 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483824 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483846 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483868 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483888 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483910 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483929 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483950 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483981 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3483998 T5133 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 3484021 T5133 oasc.OpenCloseCoreStressTest.doStress Starting indexing and querying
[junit4] 2> 3484022 T5133 oasc.OpenCloseCoreStressTest.doStress
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2> Starting a 30 second cycle, seconds left: 30. Seconds run so far: 0.
[junit4] 2> 3484027 T5146 oasc.OneIndexer.run Starting indexing thread: 5146
[junit4] 2> 3484051 T5148 oasc.OneIndexer.run Starting indexing thread: 5148
[junit4] 2> 3484058 T5147 oasc.OneIndexer.run Starting indexing thread: 5147
[junit4] 2> 3484058 T5149 oasc.OneIndexer.run Starting indexing thread: 5149
[junit4] 2> 3484072 T5150 oasc.OneIndexer.run Starting indexing thread: 5150
[junit4] 2> 3484074 T5151 oasc.OneIndexer.run Starting indexing thread: 5151
[junit4] 2> 3484076 T5152 oasc.OneIndexer.run Starting indexing thread: 5152
[junit4] 2> 3484077 T5153 oasc.OneIndexer.run Starting indexing thread: 5153
[junit4] 2> 3484106 T5168 oasc.OneQuery.run Starting query thread: 5168
[junit4] 2> 3484100 T5167 oasc.OneQuery.run Starting query thread: 5167
[junit4] 2> 3484099 T5166 oasc.OneQuery.run Starting query thread: 5166
[junit4] 2> 3484099 T5165 oasc.OneQuery.run Starting query thread: 5165
[junit4] 2> 3484098 T5164 oasc.OneQuery.run Starting query thread: 5164
[junit4] 2> 3484098 T5163 oasc.OneQuery.run Starting query thread: 5163
[junit4] 2> 3484097 T5162 oasc.OneQuery.run Starting query thread: 5162
[junit4] 2> 3484096 T5161 oasc.OneQuery.run Starting query thread: 5161
[junit4] 2> 3484092 T5160 oasc.OneIndexer.run Starting indexing thread: 5160
[junit4] 2> 3484091 T5159 oasc.OneIndexer.run Starting indexing thread: 5159
[junit4] 2> 3484091 T5158 oasc.OneIndexer.run Starting indexing thread: 5158
[junit4] 2> 3484090 T5157 oasc.OneIndexer.run Starting indexing thread: 5157
[junit4] 2> 3484089 T5156 oasc.OneIndexer.run Starting indexing thread: 5156
[junit4] 2> 3484088 T5155 oasc.OneIndexer.run Starting indexing thread: 5155
[junit4] 2> 3484087 T5154 oasc.OneIndexer.run Starting indexing thread: 5154
[junit4] 2> 3484183 T5179 oasc.CoreContainer.create Creating SolrCore '00006_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00006_core
[junit4] 2> 3484184 T5179 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00006_core/'
[junit4] 2> 3484185 T5181 oasc.CoreContainer.create Creating SolrCore '00009_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00009_core
[junit4] 2> 3484186 T5181 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00009_core/'
[junit4] 2> 3484150 T5177 oasc.CoreContainer.create Creating SolrCore '00018_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00018_core
[junit4] 2> 3484189 T5177 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00018_core/'
[junit4] 2> 3484121 T5175 oasc.OneQuery.run Starting query thread: 5175
[junit4] 2> 3484121 T5174 oasc.OneQuery.run Starting query thread: 5174
[junit4] 2> 3484120 T5138 oasc.CoreContainer.create Creating SolrCore '00016_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00016_core
[junit4] 2> 3484206 T5138 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00016_core/'
[junit4] 2> 3484119 T5137 oasc.CoreContainer.create Creating SolrCore '00007_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00007_core
[junit4] 2> 3484211 T5137 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00007_core/'
[junit4] 2> 3484116 T5173 oasc.OneQuery.run Starting query thread: 5173
[junit4] 2> 3484115 T5172 oasc.OneQuery.run Starting query thread: 5172
[junit4] 2> 3484114 T5171 oasc.OneQuery.run Starting query thread: 5171
[junit4] 2> 3484113 T5170 oasc.OneQuery.run Starting query thread: 5170
[junit4] 2> 3484112 T5169 oasc.OneQuery.run Starting query thread: 5169
[junit4] 2> 3484347 T5185 oasc.CoreContainer.create Creating SolrCore '00001_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00001_core
[junit4] 2> 3484348 T5185 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00001_core/'
[junit4] 2> 3484349 T5189 oasc.CoreContainer.create Creating SolrCore '00015_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00015_core
[junit4] 2> 3484350 T5189 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00015_core/'
[junit4] 2> 3484356 T5186 oasc.CoreContainer.create Creating SolrCore '00008_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00008_core
[junit4] 2> 3484357 T5186 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00008_core/'
[junit4] 2> 3484111 T5140 oasc.CoreContainer.create Creating SolrCore '00014_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00014_core
[junit4] 2> 3484361 T5140 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00014_core/'
[junit4] 2> 3484109 T5142 oasc.CoreContainer.create Creating SolrCore '00010_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00010_core
[junit4] 2> 3484362 T5142 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00010_core/'
[junit4] 2> 3484365 T5193 oasc.CoreContainer.create Creating SolrCore '00003_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00003_core
[junit4] 2> 3484365 T5193 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00003_core/'
[junit4] 2> 3484109 T5141 oasc.CoreContainer.create Creating SolrCore '00013_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00013_core
[junit4] 2> 3484391 T5141 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00013_core/'
[junit4] 2> ASYNC NEW_CORE C1342 name=00000_core org.apache.solr.core.SolrCore@10f57dd0
[junit4] 2> 3484390 T5178 C1342 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00000_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6b926d6d),segFN=segments_1,generation=1}
[junit4] 2> 3484348 T5188 C1342 oasc.SolrCore.execute [00000_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=1
[junit4] 2> 3484324 T5184 oasc.CoreContainer.create Creating SolrCore '00019_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00019_core
[junit4] 2> 3484422 T5184 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00019_core/'
[junit4] 2> 3484417 T5178 C1342 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3484455 T5178 C1342 oasup.LogUpdateProcessor.finish [00000_core] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id9]} 0 276
[junit4] 2> 3484497 T5179 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4] 2> 3484513 T5178 oasc.CoreContainer.create Creating SolrCore '00017_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00017_core
[junit4] 2> 3484514 T5178 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00017_core/'
[junit4] 2> 3485007 T5137 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4] 2> 3485024 T5177 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4] 2> 3485103 T5140 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4] 2> 3485114 T5181 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4] 2> 3485203 T5138 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4] 2> 3485408 T5185 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4] 2> 3485433 T5179 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-minimal.xml
[junit4] 2> 3485435 T5179 oass.IndexSchema.readSchema Reading Solr Schema from schema-tiny.xml
[junit4] 2> 3485447 T5179 oass.IndexSchema.readSchema [00006_core] Schema name=tiny
[junit4] 2> 3485494 T5189 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4] 2> 3485549 T5184 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4] 2> 3485560 T5193 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4] 2> 3485724 T5179 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3485727 T5179 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockFSDirectoryFactory
[junit4] 2> 3485728 T5179 oasc.SolrCore.<init> [00006_core] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00006_core/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00006_core/data/
[junit4] 2> 3485729 T5179 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6feeae6
[junit4] 2> 3485835 T5179 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00006_core/data
[junit4] 2> 3485844 T5179 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00006_core/data/index/
[junit4] 2> 3485846 T5179 oasc.SolrCore.initIndex WARN [00006_core] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00006_core/data/index' doesn't exist. Creating new index...
[junit4] 2> 3485911 T5179 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00006_core/data/index
[junit4] 2> 3485972 T5186 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4] 2> 3485980 T5137 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-minimal.xml
[junit4] 2> 3485982 T5137 oass.IndexSchema.readSchema Reading Solr Schema from schema-tiny.xml
[junit4] 2> 3485998 T5141 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4] 2> 3485999 T5178 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4] 2> 3486019 T5179 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00006_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@30629716),segFN=segments_1,generation=1}
[junit4] 2> 3486020 T5179 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3486021 T5179 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 3486028 T5179 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 3486043 T5179 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 3486044 T5179 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3486047 T5179 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3486057 T5142 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4] 2> 3486101 T5138 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-minimal.xml
[junit4] 2> 3486102 T5138 oass.IndexSchema.readSchema Reading Solr Schema from schema-tiny.xml
[junit4] 2> 3486109 T5177 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-minimal.xml
[junit4] 2> 3486110 T5177 oass.IndexSchema.readSchema Reading Solr Schema from schema-tiny.xml
[junit4] 2> 3486133 T5137 oass.IndexSchema.readSchema [00007_core] Schema name=tiny
[junit4] 2> 3486134 T5177 oass.IndexSchema.readSchema [00018_core] Schema name=tiny
[junit4] 2> 3486138 T5138 oass.IndexSchema.readSchema [00016_core] Schema name=tiny
[junit4] 2> 3486384 T5179 oass.SolrIndexSearcher.<init> Opening Searcher@720ccefa main
[junit4] 2> 3486386 T5179 oasc.SolrCore.registerSearcher [00006_core] Registered new searcher Searcher@720ccefa main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 3486387 T5179 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3486387 T5179 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 3486396 T5184 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-minimal.xml
[junit4] 2> 3486396 T5179 oasc.SolrCores.putTransientCore Opening transient core 00006_core
[junit4] 2> 3486398 T5179 oasc.CoreContainer.registerCore registering core: 00006_core
[junit4] 2> 3486397 T5184 oass.IndexSchema.readSchema Reading Solr Schema from schema-tiny.xml
[junit4] 2> ASYNC NEW_CORE C1343 name=00006_core org.apache.solr.core.SolrCore@220992d9
[junit4] 2> 3486477 T5179 C1343 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00006_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@30629716),segFN=segments_1,generation=1}
[junit4] 2> 3486478 T5179 C1343 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3486489 T5181 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-minimal.xml
[junit4] 2> 3486491 T5181 oass.IndexSchema.readSchema Reading Solr Schema from schema-tiny.xml
[junit4] 2> 3486500 T5140 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-minimal.xml
[junit4] 2> 3486501 T5140 oass.IndexSchema.readSchema Reading Solr Schema from schema-tiny.xml
[junit4] 2> 3486508 T5179 C1343 oasup.LogUpdateProcessor.finish [00006_core] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id11]} 0 80
[junit4] 2> 3486522 T5202 oasc.CoreContainer.create Creating SolrCore '00011_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00011_core
[junit4] 2> 3486523 T5202 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00011_core/'
[junit4] 2> 3486529 T5181 oass.IndexSchema.readSchema [00009_core] Schema name=tiny
[junit4] 2> 3486539 T5201 C1343 oasup.LogUpdateProcessor.finish [00006_core] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id16]} 0 0
[junit4] 2> 3486549 T5179 oasc.CoreContainer.create Creating SolrCore '00012_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00012_core
[junit4] 2> 3486549 T5179 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00012_core/'
[junit4] 2> 3486549 T5184 oass.IndexSchema.readSchema [00019_core] Schema name=tiny
[junit4] 2> 3486558 T5185 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-minimal.xml
[junit4] 2> 3486560 T5185 oass.IndexSchema.readSchema Reading Solr Schema from schema-tiny.xml
[junit4] 2> 3486587 T5185 oass.IndexSchema.readSchema [00001_core] Schema name=tiny
[junit4] 2> 3486612 T5137 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3486615 T5137 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockFSDirectoryFactory
[junit4] 2> 3486616 T5137 oasc.SolrCore.<init> [00007_core] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00007_core/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00007_core/data/
[junit4] 2> 3486617 T5137 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6feeae6
[junit4] 2> 3486630 T5138 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3486633 T5138 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockFSDirectoryFactory
[junit4] 2> 3486634 T5138 oasc.SolrCore.<init> [00016_core] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00016_core/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00016_core/data/
[junit4] 2> 3486648 T5138 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6feeae6
[junit4] 2> 3486665 T5137 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00007_core/data
[junit4] 2> 3486674 T5184 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3486679 T5184 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockFSDirectoryFactory
[junit4] 2> 3486680 T5184 oasc.SolrCore.<init> [00019_core] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00019_core/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00019_core/data/
[junit4] 2> 3486681 T5184 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6feeae6
[junit4] 2> 3486782 T5138 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00016_core/data
[junit4] 2> 3486784 T5137 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00007_core/data/index/
[junit4] 2> 3486785 T5137 oasc.SolrCore.initIndex WARN [00007_core] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00007_core/data/index' doesn't exist. Creating new index...
[junit4] 2> 3486793 T5193 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-minimal.xml
[junit4] 2> 3486795 T5193 oass.IndexSchema.readSchema Reading Solr Schema from schema-tiny.xml
[junit4] 2> 3486797 T5137 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00007_core/data/index
[junit4] 2> 3486798 T5138 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00016_core/data/index/
[junit4] 2> 3486799 T5138 oasc.SolrCore.initIndex WARN [00016_core] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00016_core/data/index' doesn't exist. Creating new index...
[junit4] 2> 3486810 T5138 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00016_core/data/index
[junit4] 2> 3486825 T5184 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00019_core/data
[junit4] 2> 3486864 T5181 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3486873 T5181 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockFSDirectoryFactory
[junit4] 2> 3486875 T5181 oasc.SolrCore.<init> [00009_core] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00009_core/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00009_core/data/
[junit4] 2> 3486876 T5181 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6feeae6
[junit4] 2> 3486907 T5184 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00019_core/data/index/
[junit4] 2> 3486923 T5184 oasc.SolrCore.initIndex WARN [00019_core] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00019_core/data/index' doesn't exist. Creating new index...
[junit4] 2> 3486905 T5177 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3486933 T5177 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockFSDirectoryFactory
[junit4] 2> 3486935 T5177 oasc.SolrCore.<init> [00018_core] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00018_core/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00018_core/data/
[junit4] 2> 3486936 T5177 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6feeae6
[junit4] 2> 3486946 T5137 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00007_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@72f91c),segFN=segments_1,generation=1}
[junit4] 2> 3486948 T5137 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3486892 T5193 oass.IndexSchema.readSchema [00003_core] Schema name=tiny
[junit4] 2> 3486887 T5140 oass.IndexSchema.readSchema [00014_core] Schema name=tiny
[junit4] 2> 3486968 T5137 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 3486978 T5184 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00019_core/data/index
[junit4] 2> 3486985 T5137 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 3486986 T5137 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 3486988 T5137 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3486991 T5138 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00016_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2cc1204b),segFN=segments_1,generation=1}
[junit4] 2> 3486992 T5138 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3487009 T5138 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 3487042 T5138 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 3487043 T5138 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 3487045 T5138 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3487044 T5177 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00018_core/data
[junit4] 2> 3487085 T5177 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00018_core/data/index/
[junit4] 2> 3487087 T5177 oasc.SolrCore.initIndex WARN [00018_core] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00018_core/data/index' doesn't exist. Creating new index...
[junit4] 2> 3487089 T5185 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3487091 T5185 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockFSDirectoryFactory
[junit4] 2> 3487093 T5185 oasc.SolrCore.<init> [00001_core] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00001_core/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00001_core/data/
[junit4] 2> 3487094 T5185 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6feeae6
[junit4] 2> 3487110 T5181 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00009_core/data
[junit4] 2> 3487125 T5181 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00009_core/data/index/
[junit4] 2> 3487128 T5181 oasc.SolrCore.initIndex WARN [00009_core] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00009_core/data/index' doesn't exist. Creating new index...
[junit4] 2> 3487138 T5184 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00019_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7ffe24f2),segFN=segments_1,generation=1}
[junit4] 2> 3487139 T5184 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3487140 T5184 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 3487160 T5181 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00009_core/data/index
[junit4] 2> 3487163 T5184 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 3487164 T5184 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 3487164 T5186 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-minimal.xml
[junit4] 2> 3487166 T5177 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00018_core/data/index
[junit4] 2> 3487165 T5184 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3487181 T5184 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3487181 T5186 oass.IndexSchema.readSchema Reading Solr Schema from schema-tiny.xml
[junit4] 2> 3487181 T5138 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3487216 T5185 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00001_core/data
[junit4] 2> 3487216 T5181 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00009_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@41462e00),segFN=segments_1,generation=1}
[junit4] 2> 3487218 T5181 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3487230 T5181 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 3487240 T5185 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00001_core/data/index/
[junit4] 2> 3487242 T5185 oasc.SolrCore.initIndex WARN [00001_core] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00001_core/data/index' doesn't exist. Creating new index...
[junit4] 2> 3487244 T5137 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3487250 T5177 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00018_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@69ccefbd),segFN=segments_1,generation=1}
[junit4] 2> 3487251 T5177 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3487258 T5181 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 3487260 T5181 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 3487262 T5181 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3487265 T5177 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 3487355 T5177 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 3487356 T5177 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 3487363 T5177 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3487360 T5142 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-minimal.xml
[junit4] 2> 3487374 T5184 oass.SolrIndexSearcher.<init> Opening Searcher@8bbfdd1 main
[junit4] 2> 3487376 T5184 oasc.SolrCore.registerSearcher [00019_core] Registered new searcher Searcher@8bbfdd1 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 3487377 T5184 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3487377 T5184 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 3487378 T5186 oass.IndexSchema.readSchema [00008_core] Schema name=tiny
[junit4] 2> 3487385 T5177 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3487389 T5184 oasc.SolrCores.putTransientCore Opening transient core 00019_core
[junit4] 2> 3487390 T5137 oass.SolrIndexSearcher.<init> Opening Searcher@14ac05f5 main
[junit4] 2> 3487396 T5137 oasc.SolrCore.registerSearcher [00007_core] Registered new searcher Searcher@14ac05f5 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 3487397 T5137 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3487398 T5137 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 3487390 T5185 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00001_core/data/index
[junit4] 2> 3487391 T5181 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3487425 T5137 oasc.SolrCores.putTransientCore Opening transient core 00007_core
[junit4] 2> 3487394 T5189 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-minimal.xml
[junit4] 2> 3487437 T5189 oass.IndexSchema.readSchema Reading Solr Schema from schema-tiny.xml
[junit4] 2> 3487435 T5142 oass.IndexSchema.readSchema Reading Solr Schema from schema-tiny.xml
[junit4] 2> 3487433 T5137 oasc.CoreContainer.registerCore registering core: 00007_core
[junit4] 2> 3487432 T5184 oasc.CoreContainer.registerCore registering core: 00019_core
[junit4] 2> 3487465 T5141 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-minimal.xml
[junit4] 2> 3487467 T5141 oass.IndexSchema.readSchema Reading Solr Schema from schema-tiny.xml
[junit4] 2> ASYNC NEW_CORE C1344 name=00019_core org.apache.solr.core.SolrCore@9e722ca
[junit4] 2> 3487471 T5187 C1344 oasc.SolrCore.execute [00019_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=0
[junit4] 2> 3487487 T5193 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3487490 T5141 oass.IndexSchema.readSchema [00013_core] Schema name=tiny
[junit4] 2> 3487491 T5193 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockFSDirectoryFactory
[junit4] 2> 3487496 T5193 oasc.SolrCore.<init> [00003_core] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00003_core/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00003_core/data/
[junit4] 2> 3487520 T5193 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6feeae6
[junit4] 2> 3487524 T5193 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00003_core/data
[junit4] 2> 3487525 T5193 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00003_core/data/index/
[junit4] 2> 3487526 T5193 oasc.SolrCore.initIndex WARN [00003_core] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00003_core/data/index' doesn't exist. Creating new index...
[junit4] 2> 3487527 T5193 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00003_core/data/index
[junit4] 2> 3487493 T5138 oass.SolrIndexSearcher.<init> Opening Searcher@7ba6f710 main
[junit4] 2> 3487532 T5138 oasc.SolrCore.registerSearcher [00016_core] Registered new searcher Searcher@7ba6f710 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 3487544 T5138 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3487544 T5138 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 3487492 T5177 oass.SolrIndexSearcher.<init> Opening Searcher@2cc933df main
[junit4] 2> 3487513 T5198 C1344 oasc.SolrCore.execute [00019_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=0
[junit4] 2> 3487513 T5189 oass.IndexSchema.readSchema [00015_core] Schema name=tiny
[junit4] 2> 3487507 T5192 C1344 oasc.SolrCore.execute [00019_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=0
[junit4] 2> 3487556 T5138 oasc.SolrCores.putTransientCore Opening transient core 00016_core
[junit4] 2> 3487565 T5138 oasc.CoreContainer.registerCore registering core: 00016_core
[junit4] 2> 3487550 T5177 oasc.SolrCore.registerSearcher [00018_core] Registered new searcher Searcher@2cc933df main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 3487579 T5177 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3487579 T5177 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 3487588 T5201 oasc.CoreContainer.create Creating SolrCore '00005_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00005_core
[junit4] 2> 3487589 T5201 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00005_core/'
[junit4] 2> 3487589 T5202 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4] 2> 3487602 T5142 oass.IndexSchema.readSchema [00010_core] Schema name=tiny
[junit4] 2> 3487606 T5140 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3487614 T5177 oasc.SolrCores.putTransientCore Opening transient core 00018_core
[junit4] 2> 3487615 T5177 oasc.CoreContainer.registerCore registering core: 00018_core
[junit4] 2> ASYNC NEW_CORE C1345 name=00018_core org.apache.solr.core.SolrCore@7aa2372a
[junit4] 2> 3487629 T5190 C1345 oasc.SolrCore.execute [00018_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=1
[junit4] 2> 3487639 T5185 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00001_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@327dc4fe),segFN=segments_1,generation=1}
[junit4] 2> 3487640 T5185 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3487650 T5185 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> ASYNC NEW_CORE C1346 name=00007_core org.apache.solr.core.SolrCore@3c882df5
[junit4] 2> 3487652 T5182 C1346 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00007_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@72f91c),segFN=segments_1,generation=1}
[junit4] 2> 3487659 T5182 C1346 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3487686 T5185 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 3487688 T5185 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 3487689 T5185 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3487691 T5198 C1345 oasc.SolrCore.execute [00018_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=0
[junit4] 2> 3487709 T5181 oass.SolrIndexSearcher.<init> Opening Searcher@33ca1424 main
[junit4] 2> 3487710 T5181 oasc.SolrCore.registerSearcher [00009_core] Registered new searcher Searcher@33ca1424 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 3487711 T5181 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3487712 T5181 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 3487721 T5185 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3487730 T5181 oasc.SolrCores.putTransientCore Opening transient core 00009_core
[junit4] 2> 3487731 T5181 oasc.CoreContainer.registerCore registering core: 00009_core
[junit4] 2> ASYNC NEW_CORE C1347 name=00009_core org.apache.solr.core.SolrCore@6c842c76
[junit4] 2> 3487744 T5200 C1347 oasc.SolrCore.execute [00009_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=1
[junit4] 2> 3487744 T5192 C1344 oasc.SolrCore.execute [00019_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=0
[junit4] 2> 3487752 T5182 C1346 oasup.LogUpdateProcessor.finish [00007_core] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id12]} 0 295
[junit4] 2> 3487752 T5183 C1346 oasup.LogUpdateProcessor.finish [00007_core] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id14]} 0 214
[junit4] 2> 3487753 T5137 C1346 oasup.LogUpdateProcessor.finish [00007_core] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id4]} 0 208
[junit4] 2> 3487761 T5193 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00003_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6d7b12eb),segFN=segments_1,generation=1}
[junit4] 2> 3487762 T5193 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3487763 T5193 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 3487771 T5184 C1344 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00019_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7ffe24f2),segFN=segments_1,generation=1}
[junit4] 2> 3487772 T5184 C1344 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3487774 T5193 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 3487777 T5140 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockFSDirectoryFactory
[junit4] 2> 3487779 T5140 oasc.SolrCore.<init> [00014_core] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00014_core/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00014_core/data/
[junit4] 2> 3487780 T5140 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6feeae6
[junit4] 2> 3487794 T5140 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00014_core/data
[junit4] 2> 3487795 T5184 C1344 oasup.LogUpdateProcessor.finish [00019_core] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id15]} 0 181
[junit4] 2> 3487799 T5198 oasc.CoreContainer.create Creating SolrCore '00002_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00002_core
[junit4] 2> 3487801 T5198 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00002_core/'
[junit4] 2> 3487808 T5193 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 3487809 T5193 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3487812 T5140 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00014_core/data/index/
[junit4] 2> 3487813 T5140 oasc.SolrCore.initIndex WARN [00014_core] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00014_core/data/index' doesn't exist. Creating new index...
[junit4] 2> ASYNC NEW_CORE C1348 name=00016_core org.apache.solr.core.SolrCore@28fce59c
[junit4] 2> 3487800 T5138 C1348 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00016_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2cc1204b),segFN=segments_1,generation=1}
[junit4] 2> 3487815 T5138 C1348 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3487818 T5140 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00014_core/data/index
[junit4] 2> 3487827 T5140 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00014_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2431bb16),segFN=segments_1,generation=1}
[junit4] 2> 3487828 T5140 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3487829 T5140 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 3487830 T5179 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4] 2> 3487819 T5177 C1345 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00018_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@69ccefbd),segFN=segments_1,generation=1}
[junit4] 2> 3487837 T5177 C1345 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3487841 T5140 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 3487843 T5140 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 3487844 T5140 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3487842 T5193 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> ASYNC NEW_CORE C1349 name=00018_core org.apache.solr.core.SolrCore@7aa2372a
[junit4] 2> 3487956 T5177 C1349 oasup.LogUpdateProcessor.finish [00018_core] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id8]} 0 192
[junit4] 2> 3487866 T5185 oass.SolrIndexSearcher.<init> Opening Searcher@7b6b5c56 main
[junit4] 2> ASYNC NEW_CORE C1350 name=00009_core org.apache.solr.core.SolrCore@6c842c76
[junit4] 2> 3487865 T5192 C1350 oasc.SolrCore.execute [00009_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=0
[junit4] 2> ASYNC NEW_CORE C1351 name=00016_core org.apache.solr.core.SolrCore@28fce59c
[junit4] 2> 3487864 T5187 C1351 oasc.SolrCore.execute [00016_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=0
[junit4] 2> 3487859 T5137 oasc.CoreContainer.create Creating SolrCore '00004_core' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00004_core
[junit4] 2> 3487970 T5137 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00004_core/'
[junit4] 2> 3488008 T5185 oasc.SolrCore.registerSearcher [00001_core] Registered new searcher Searcher@7b6b5c56 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 3488009 T5185 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3488010 T5185 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 3488029 T5178 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-minimal.xml
[junit4] 2> 3488030 T5178 oass.IndexSchema.readSchema Reading Solr Schema from schema-tiny.xml
[junit4] 2> 3488035 T5197 C1349 oasc.SolrCore.execute [00018_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=1
[junit4] 2> 3488049 T5138 C1351 oasup.LogUpdateProcessor.finish [00016_core] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id5]} 0 283
[junit4] 2> 3488102 T5185 oasc.SolrCores.putTransientCore Opening transient core 00001_core
[junit4] 2> 3488112 T5185 oasc.CoreContainer.registerCore registering core: 00001_core
[junit4] 2> 3488098 T5193 oass.SolrIndexSearcher.<init> Opening Searcher@668b0ad7 main
[junit4] 2> 3488115 T5193 oasc.SolrCore.registerSearcher [00003_core] Registered new searcher Searcher@668b0ad7 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 3488115 T5193 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3488116 T5193 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> ASYNC NEW_CORE C1352 name=00006_core org.apache.solr.core.SolrCore@220992d9
[junit4] 2> 3488119 T5187 C1352 oasup.LogUpdateProcessor.finish [00006_core] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id24]} 0 1
[junit4] 2> 3488097 T5142 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3488148 T5142 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockFSDirectoryFactory
[junit4] 2> 3488149 T5142 oasc.SolrCore.<init> [00010_core] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00010_core/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00010_core/data/
[junit4] 2> 3488150 T5142 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6feeae6
[junit4] 2> 3488052 T5140 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3488157 T5189 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3488163 T5189 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockFSDirectoryFactory
[junit4] 2> 3488165 T5189 oasc.SolrCore.<init> [00015_core] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00015_core/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00015_core/data/
[junit4] 2> 3488169 T5189 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6feeae6
[junit4] 2> 3488086 T5141 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3488160 T5140 oass.SolrIndexSearcher.<init> Opening Searcher@496a6524 main
[junit4] 2> 3488173 T5140 oasc.SolrCore.registerSearcher [00014_core] Registered new searcher Searcher@496a6524 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 3488174 T5140 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3488177 T5140 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 3488158 T5142 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00010_core/data
[junit4] 2> 3488148 T5193 oasc.SolrCores.putTransientCore Opening transient core 00003_core
[junit4] 2> 3488246 T5193 oasc.CoreContainer.registerCore registering core: 00003_core
[junit4] 2> 3488231 T5140 oasc.SolrCores.putTransientCore Opening transient core 00014_core
[junit4] 2> 3488253 T5140 oasc.CoreContainer.registerCore registering core: 00014_core
[junit4] 2> 3488230 T5181 C1350 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00009_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@41462e00),segFN=segments_1,generation=1}
[junit4] 2> 3488256 T5181 C1350 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3488221 T5178 oass.IndexSchema.readSchema [00017_core] Schema name=tiny
[junit4] 2> 3488215 T5141 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockFSDirectoryFactory
[junit4] 2> 3488266 T5141 oasc.SolrCore.<init> [00013_core] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00013_core/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00013_core/data/
[junit4] 2> 3488266 T5141 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6feeae6
[junit4] 2> ASYNC NEW_CORE C1353 name=00001_core org.apache.solr.core.SolrCore@64ec40d
[junit4] 2> 3488206 T5185 C1353 oasc.SolrCore.execute [00001_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=0
[junit4] 2> 3488203 T5186 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3488266 T5197 C1353 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00001_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@327dc4fe),segFN=segments_1,generation=1}
[junit4] 2> 3488275 T5197 C1353 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3488260 T5142 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00010_core/data/index/
[junit4] 2> 3488276 T5189 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00015_core/data
[junit4] 2> 3488278 T5142 oasc.SolrCore.initIndex WARN [00010_core] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00010_core/data/index' doesn't exist. Creating new index...
[junit4] 2> 3488283 T5141 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00013_core/data
[junit4] 2> 3488284 T5189 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00015_core/data/index/
[junit4] 2> 3488294 T5142 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00010_core/data/index
[junit4] 2> 3488296 T5189 oasc.SolrCore.initIndex WARN [00015_core] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00015_core/data/index' doesn't exist. Creating new index...
[junit4] 2> 3488296 T5141 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00013_core/data/index/
[junit4] 2> 3488298 T5141 oasc.SolrCore.initIndex WARN [00013_core] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00013_core/data/index' doesn't exist. Creating new index...
[junit4] 2> 3488303 T5181 C1350 oasup.LogUpdateProcessor.finish [00009_core] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id13]} 0 252
[junit4] 2> 3488304 T5197 C1353 oasup.LogUpdateProcessor.finish [00001_core] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id25]} 0 124
[junit4] 2> 3488315 T5186 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockFSDirectoryFactory
[junit4] 2> 3488316 T5186 oasc.SolrCore.<init> [00008_core] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./OpenCloseCoreStressTest_/00008_core/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00008_core/data/
[junit4] 2> 3488316 T5186 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6feeae6
[junit4] 2> 3488324 T5141 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00013_core/data/index
[junit4] 2> ASYNC NEW_CORE C1354 name=00003_core org.apache.solr.core.SolrCore@23ffd66d
[junit4] 2> 3488326 T5193 C1354 oasc.SolrCore.execute [00003_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=1
[junit4] 2> 3488329 T5189 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00015_core/data/index
[junit4] 2> 3488349 T5186 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00008_core/data
[junit4] 2> 3488351 T5186 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00008_core/data/index/
[junit4] 2> 3488353 T5141 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00013_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2b5a5d7a),segFN=segments_1,generation=1}
[junit4] 2> 3488354 T5141 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3488355 T5141 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 3488363 T5141 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 3488364 T5141 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> ASYNC NEW_CORE C1355 name=00014_core org.apache.solr.core.SolrCore@1c3111a4
[junit4] 2> 3488367 T5176 C1355 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00014_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2431bb16),segFN=segments_1,generation=1}
[junit4] 2> 3488372 T5176 C1355 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3488372 T5141 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3488385 T5189 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00015_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@55fba83),segFN=segments_1,generation=1}
[junit4] 2> 3488386 T5189 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3488387 T5189 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 3488394 T5189 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 3488395 T5189 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 3488396 T5189 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3488417 T5142 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00010_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@58be34ef),segFN=segments_1,generation=1}
[junit4] 2> 3488422 T5142 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3488417 T5176 C1355 oasup.LogUpdateProcessor.finish [00014_core] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id7]} 0 129
[junit4] 2> 3488417 T5197 C1355 oasup.LogUpdateProcessor.finish [00014_core] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id26]} 0 105
[junit4] 2> 3488414 T5186 oasc.SolrCore.initIndex WARN [00008_core] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00008_core/data/index' doesn't exist. Creating new index...
[junit4] 2> 3488398 T5195 C1354 oasc.SolrCore.execute [00003_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=0
[junit4] 2> 3488433 T5193 C1352 oasup.LogUpdateProcessor.finish [00006_core] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id29]} 0 1
[junit4] 2> 3488434 T5176 C1349 oasc.SolrCore.execute [00018_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=0
[junit4] 2> 3488435 T5142 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> ASYNC NEW_CORE C1356 name=00014_core org.apache.solr.core.SolrCore@1c3111a4
[junit4] 2> 3488435 T5140 C1356 oasup.LogUpdateProcessor.finish [00014_core] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id2]} 0 112
[junit4] 2> 3488440 T5186 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00008_core/data/index
[junit4] 2> 3488518 T5142 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 3488519 T5142 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 3488520 T5142 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> ASYNC NEW_CORE C1357 name=00016_core org.apache.solr.core.SolrCore@28fce59c
[junit4] 2> 3488533 T5176 C1357 oasc.SolrCore.execute [00016_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=0
[junit4] 2> ASYNC NEW_CORE C1358 name=00001_core org.apache.solr.core.SolrCore@64ec40d
[junit4] 2> 3488539 T5140 C1358 oasc.SolrCore.execute [00001_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=0
[junit4] 2> 3488543 T5142 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3488552 T5189 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3488574 T5189 oass.SolrIndexSearcher.<init> Opening Searcher@3dd7021b main
[junit4] 2> 3488575 T5189 oasc.SolrCore.registerSearcher [00015_core] Registered new searcher Searcher@3dd7021b main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 3488576 T5189 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3488576 T5189 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 3488581 T5186 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00008_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6ecb5a54),segFN=segments_1,generation=1}
[junit4] 2> 3488591 T5186 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3488597 T5186 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 3488601 T5189 oasc.SolrCores.putTransientCore Opening transient core 00015_core
[junit4] 2> 3488601 T5189 oasc.CoreContainer.registerCore registering core: 00015_core
[junit4] 2> 3488574 T5141 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3488610 T5186 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 3488612 T5186 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 3488615 T5186 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3488627 T5141 oass.SolrIndexSearcher.<init> Opening Searcher@197b7646 main
[junit4] 2> 3488630 T5141 oasc.SolrCore.registerSearcher [00013_core] Registered new searcher Searcher@197b7646 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 3488631 T5141 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3488631 T5141 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 3488646 T5141 oasc.SolrCores.putTransientCore Opening transient core 00013_core
[junit4] 2> 3488647 T5141 oasc.CoreContainer.registerCore registering core: 00013_core
[junit4] 2> ASYNC NEW_CORE C1359 name=00015_core org.apache.solr.core.SolrCore@68164423
[junit4] 2> 3488658 T5182 C1359 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00015_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@55fba83),segFN=segments_1,generation=1}
[junit4] 2> 3488663 T5182 C1359 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3488674 T5177 C1359 oasc.SolrCore.execute [00015_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=0
[junit4] 2> 3488679 T5142 oass.SolrIndexSearcher.<init> Opening Searcher@2d34520f main
[junit4] 2> 3488681 T5142 oasc.SolrCore.registerSearcher [00010_core] Registered new searcher Searcher@2d34520f main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 3488682 T5142 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3488683 T5186 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3488685 T5189 C1359 oasc.SolrCore.execute [00015_core] webapp=/solr path=/select params={q=*:*&wt=javabin&qt=/select&version=2} hits=0 status=0 QTime=0
[junit4] 2> 3488686 T5142 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 3488695 T5142 oasc.SolrCores.putTransientCore Opening transient core 00010_core
[junit4] 2> 3488696 T5142 oasc.CoreContainer.registerCore registering core: 00010_core
[junit4] 2> 3488706 T5199 C1359 oasc.SolrCore.execute [00015_core] webapp=/solr path=/select params={q=*:*&wt=javabin&q
[...truncated too long message...]
ex
[junit4] 2> 3560167 T5133 oasc.SolrCore.close [00008_core] CLOSING SolrCore org.apache.solr.core.SolrCore@68013952
[junit4] 2> 3560186 T5133 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=5,autocommits=0,soft autocommits=5,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=607,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=607,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 3560188 T5133 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 3560189 T5133 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 3560191 T5133 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> ASYNC NEW_CORE C1720 name=00008_core org.apache.solr.core.SolrCore@68013952
[junit4] 2> 3560236 T5133 C1720 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00008_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@501ee05),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00008_core/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@501ee05),segFN=segments_2,generation=2}
[junit4] 2> 3560236 T5133 C1720 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 3560238 T5133 oasc.SolrCore.closeSearcher [00008_core] Closing main searcher on request.
[junit4] 2> 3560341 T5133 oasc.CachingDirectoryFactory.close Closing MockFSDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 3560343 T5133 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00008_core/data [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00008_core/data;done=false>>]
[junit4] 2> 3560344 T5133 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00008_core/data
[junit4] 2> 3560346 T5133 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00008_core/data/index [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00008_core/data/index;done=false>>]
[junit4] 2> 3560347 T5133 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00008_core/data/index
[junit4] 2> 3560464 T5133 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 3561775 T5133 oas.SolrTestCaseJ4.tearDown ###Ending test30SecondsNew
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OpenCloseCoreStressTest -Dtests.method=test30SecondsNew -Dtests.seed=F4F018FC62AFA912 -Dtests.slow=true -Dtests.locale=es_BO -Dtests.timezone=Africa/Niamey -Dtests.file.encoding=UTF-8
[junit4] FAILURE 40.0s | OpenCloseCoreStressTest.test30SecondsNew <<<
[junit4] > Throwable #1: java.lang.AssertionError: Core 00000_core bad! expected:<577> but was:<0>
[junit4] > at __randomizedtesting.SeedInfo.seed([F4F018FC62AFA912:90450428306F5057]:0)
[junit4] > at org.apache.solr.core.OpenCloseCoreStressTest.checkResults(OpenCloseCoreStressTest.java:307)
[junit4] > at org.apache.solr.core.OpenCloseCoreStressTest.doStress(OpenCloseCoreStressTest.java:201)
[junit4] > at org.apache.solr.core.OpenCloseCoreStressTest.test30SecondsNew(OpenCloseCoreStressTest.java:121)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] IGNOR/A 0.00s | OpenCloseCoreStressTest.test10MinutesOld
[junit4] > Assumption #1: 'nightly' test group is disabled (@Nightly)
[junit4] IGNOR/A 0.01s | OpenCloseCoreStressTest.test1HourNew
[junit4] > Assumption #1: 'weekly' test group is disabled (@Weekly)
[junit4] 2> 3561804 T5133 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=es_BO, timezone=Africa/Niamey
[junit4] 2> NOTE: Mac OS X 10.8.4 x86_64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=2,threads=1,free=100497624,total=417333248
[junit4] 2> NOTE: All tests run in this JVM: [TestSearchPerf, PreAnalyzedUpdateProcessorTest, TestIBSimilarityFactory, RequiredFieldsTest, RecoveryZkTest, FieldMutatingUpdateProcessorTest, TestSolrJ, TermsComponentTest, AutoCommitTest, TestGroupingSearch, SuggesterWFSTTest, StandardRequestHandlerTest, TestSolrIndexConfig, TestUpdate, CircularListTest, HdfsRecoveryZkTest, TestWriterPerf, DirectUpdateHandlerOptimizeTest, NumericFieldsTest, LeaderElectionIntegrationTest, ShardSplitTest, FieldAnalysisRequestHandlerTest, DocValuesMultiTest, HdfsLockFactoryTest, TestFiltering, ShowFileRequestHandlerTest, AnalysisAfterCoreReloadTest, ParsingFieldUpdateProcessorsTest, OverseerTest, TestNumberUtils, SolrCoreCheckLockOnStartupTest, TestAnalyzedSuggestions, AlternateDirectoryTest, TestDistributedSearch, SliceStateUpdateTest, TestCSVResponseWriter, NotRequiredUniqueKeyTest, TestRemoteStreaming, TestCoreContainer, TestXIncludeConfig, DisMaxRequestHandlerTest, HighlighterConfigTest, TestComponentsName, TestLFUCache, ExternalFileFieldSortTest, TestFastWriter, DOMUtilTest, DateFieldTest, StatsComponentTest, CoreMergeIndexesAdminHandlerTest, TestPostingsSolrHighlighter, DocumentBuilderTest, DistanceFunctionTest, TestInfoStreamLogging, PolyFieldTest, TestManagedSchema, TestReplicationHandler, SpellCheckCollatorTest, CSVRequestHandlerTest, SimpleFacetsTest, BasicDistributedZkTest, HighlighterTest, TestFastLRUCache, TestCloudManagedSchema, TestPartialUpdateDeduplication, CopyFieldTest, HdfsChaosMonkeySafeLeaderTest, FileUtilsTest, DeleteShardTest, ZkCLITest, MultiTermTest, XmlUpdateRequestHandlerTest, TestBinaryField, ClusterStateUpdateTest, TestPHPSerializedResponseWriter, TestZkChroot, TestDefaultSimilarityFactory, HdfsUnloadDistributedZkTest, TestJoin, TestFieldTypeCollectionResource, TestQueryTypes, WordBreakSolrSpellCheckerTest, UnloadDistributedZkTest, TestLazyCores, ReturnFieldsTest, TestDefaultSearchFieldResource, SpellPossibilityIteratorTest, FileBasedSpellCheckerTest, ResourceLoaderTest, RequestHandlersTest, TestDistributedGrouping, QueryEqualityTest, TestManagedSchemaFieldResource, EchoParamsTest, CoreContainerCoreInitFailuresTest, SliceStateTest, TestJmxMonitoredMap, DebugComponentTest, LeaderElectionTest, SimplePostToolTest, TestCopyFieldCollectionResource, ConvertedLegacyTest, StatelessScriptUpdateProcessorFactoryTest, FastVectorHighlighterTest, TestSolrXmlPersistence, TestRTGBase, TestRandomMergePolicy, DistributedSpellCheckComponentTest, IndexBasedSpellCheckerTest, TestSolrQueryParserDefaultOperatorResource, TestSchemaResource, TestFuzzyAnalyzedSuggestions, TestSolrDeletionPolicy2, TestSchemaSimilarityResource, TestSort, SolrIndexConfigTest, SyncSliceTest, UUIDFieldTest, SchemaVersionSpecificBehaviorTest, SolrInfoMBeanTest, TestRandomDVFaceting, TestPhraseSuggestions, DistributedQueryElevationComponentTest, TestStressReorder, TestUtils, IndexSchemaTest, TestPerFieldSimilarity, DirectUpdateHandlerTest, TestCSVLoader, OpenExchangeRatesOrgProviderTest, TestQuerySenderListener, ZkNodePropsTest, TestStressRecovery, TestSolrXml, StressHdfsTest, TestStressLucene, TestFunctionQuery, TestStressVersions, InfoHandlerTest, DocValuesTest, TestArbitraryIndexDir, TestFoldingMultitermQuery, UniqFieldsUpdateProcessorFactoryTest, DirectSolrSpellCheckerTest, IndexSchemaRuntimeFieldTest, SOLR749Test, ResponseLogComponentTest, TestSolrXMLSerializer, QueryParsingTest, LoggingHandlerTest, TestBadConfig, HdfsDirectoryTest, TestPluginEnable, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, OpenCloseCoreStressTest]
[junit4] Completed in 79.55s, 6 tests, 1 failure, 4 skipped <<< FAILURES!
[...truncated 481 lines...]
BUILD FAILED
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:389: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:369: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:181: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:449: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1230: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:873: There were test failures: 317 suites, 1343 tests, 1 failure, 39 ignored (5 assumptions)
Total time: 128 minutes 11 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure