You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2014/03/15 02:46:52 UTC
[JENKINS] Lucene-Solr-NightlyTests-4.x - Build # 537 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-4.x/537/
1 tests failed.
REGRESSION: org.apache.solr.handler.TestReplicationHandler.doTestReplicateAfterCoreReload
Error Message:
expected:<[{indexVersion=1394847483901,generation=2,filelist=[_ej.fdt, _ej.fdx, _ej.fnm, _ej.nvd, _ej.nvm, _ej.si, _ej_FSTOrd41_0.doc, _ej_FSTOrd41_0.tbk, _ej_FSTOrd41_0.tix, _en.fdt, _en.fdx, _en.fnm, _en.nvd, _en.nvm, _en.si, _en_FSTOrd41_0.doc, _en_FSTOrd41_0.tbk, _en_FSTOrd41_0.tix, _eo.cfe, _eo.cfs, _eo.si, _ep.fdt, _ep.fdx, _ep.fnm, _ep.nvd, _ep.nvm, _ep.si, _ep_FSTOrd41_0.doc, _ep_FSTOrd41_0.tbk, _ep_FSTOrd41_0.tix, _eq.fdt, _eq.fdx, _eq.fnm, _eq.nvd, _eq.nvm, _eq.si, _eq_FSTOrd41_0.doc, _eq_FSTOrd41_0.tbk, _eq_FSTOrd41_0.tix, _er.fdt, _er.fdx, _er.fnm, _er.nvd, _er.nvm, _er.si, _er_FSTOrd41_0.doc, _er_FSTOrd41_0.tbk, _er_FSTOrd41_0.tix, _es.fdt, _es.fdx, _es.fnm, _es.nvd, _es.nvm, _es.si, _es_FSTOrd41_0.doc, _es_FSTOrd41_0.tbk, _es_FSTOrd41_0.tix, segments_2]}]> but was:<[{indexVersion=1394847483901,generation=2,filelist=[_ej.fdt, _ej.fdx, _ej.fnm, _ej.nvd, _ej.nvm, _ej.si, _ej_FSTOrd41_0.doc, _ej_FSTOrd41_0.tbk, _ej_FSTOrd41_0.tix, _en.fdt, _en.fdx, _en.fnm, _en.nvd, _en.nvm, _en.si, _en_FSTOrd41_0.doc, _en_FSTOrd41_0.tbk, _en_FSTOrd41_0.tix, _eo.cfe, _eo.cfs, _eo.si, _ep.fdt, _ep.fdx, _ep.fnm, _ep.nvd, _ep.nvm, _ep.si, _ep_FSTOrd41_0.doc, _ep_FSTOrd41_0.tbk, _ep_FSTOrd41_0.tix, _eq.fdt, _eq.fdx, _eq.fnm, _eq.nvd, _eq.nvm, _eq.si, _eq_FSTOrd41_0.doc, _eq_FSTOrd41_0.tbk, _eq_FSTOrd41_0.tix, _er.fdt, _er.fdx, _er.fnm, _er.nvd, _er.nvm, _er.si, _er_FSTOrd41_0.doc, _er_FSTOrd41_0.tbk, _er_FSTOrd41_0.tix, _es.fdt, _es.fdx, _es.fnm, _es.nvd, _es.nvm, _es.si, _es_FSTOrd41_0.doc, _es_FSTOrd41_0.tbk, _es_FSTOrd41_0.tix, segments_2]}, {indexVersion=1394847483901,generation=3,filelist=[_en.fdt, _en.fdx, _en.fnm, _en.nvd, _en.nvm, _en.si, _en_FSTOrd41_0.doc, _en_FSTOrd41_0.tbk, _en_FSTOrd41_0.tix, _eo.cfe, _eo.cfs, _eo.si, _ep.fdt, _ep.fdx, _ep.fnm, _ep.nvd, _ep.nvm, _ep.si, _ep_FSTOrd41_0.doc, _ep_FSTOrd41_0.tbk, _ep_FSTOrd41_0.tix, _eq.fdt, _eq.fdx, _eq.fnm, _eq.nvd, _eq.nvm, _eq.si, _eq_FSTOrd41_0.doc, _eq_FSTOrd41_0.tbk, _eq_FSTOrd41_0.tix, _er.fdt, _er.fdx, _er.fnm, _er.nvd, _er.nvm, _er.si, _er_FSTOrd41_0.doc, _er_FSTOrd41_0.tbk, _er_FSTOrd41_0.tix, _es.fdt, _es.fdx, _es.fnm, _es.nvd, _es.nvm, _es.si, _es_FSTOrd41_0.doc, _es_FSTOrd41_0.tbk, _es_FSTOrd41_0.tix, _et.fdt, _et.fdx, _et.fnm, _et.nvd, _et.nvm, _et.si, _et_FSTOrd41_0.doc, _et_FSTOrd41_0.tbk, _et_FSTOrd41_0.tix, segments_3]}]>
Stack Trace:
java.lang.AssertionError: expected:<[{indexVersion=1394847483901,generation=2,filelist=[_ej.fdt, _ej.fdx, _ej.fnm, _ej.nvd, _ej.nvm, _ej.si, _ej_FSTOrd41_0.doc, _ej_FSTOrd41_0.tbk, _ej_FSTOrd41_0.tix, _en.fdt, _en.fdx, _en.fnm, _en.nvd, _en.nvm, _en.si, _en_FSTOrd41_0.doc, _en_FSTOrd41_0.tbk, _en_FSTOrd41_0.tix, _eo.cfe, _eo.cfs, _eo.si, _ep.fdt, _ep.fdx, _ep.fnm, _ep.nvd, _ep.nvm, _ep.si, _ep_FSTOrd41_0.doc, _ep_FSTOrd41_0.tbk, _ep_FSTOrd41_0.tix, _eq.fdt, _eq.fdx, _eq.fnm, _eq.nvd, _eq.nvm, _eq.si, _eq_FSTOrd41_0.doc, _eq_FSTOrd41_0.tbk, _eq_FSTOrd41_0.tix, _er.fdt, _er.fdx, _er.fnm, _er.nvd, _er.nvm, _er.si, _er_FSTOrd41_0.doc, _er_FSTOrd41_0.tbk, _er_FSTOrd41_0.tix, _es.fdt, _es.fdx, _es.fnm, _es.nvd, _es.nvm, _es.si, _es_FSTOrd41_0.doc, _es_FSTOrd41_0.tbk, _es_FSTOrd41_0.tix, segments_2]}]> but was:<[{indexVersion=1394847483901,generation=2,filelist=[_ej.fdt, _ej.fdx, _ej.fnm, _ej.nvd, _ej.nvm, _ej.si, _ej_FSTOrd41_0.doc, _ej_FSTOrd41_0.tbk, _ej_FSTOrd41_0.tix, _en.fdt, _en.fdx, _en.fnm, _en.nvd, _en.nvm, _en.si, _en_FSTOrd41_0.doc, _en_FSTOrd41_0.tbk, _en_FSTOrd41_0.tix, _eo.cfe, _eo.cfs, _eo.si, _ep.fdt, _ep.fdx, _ep.fnm, _ep.nvd, _ep.nvm, _ep.si, _ep_FSTOrd41_0.doc, _ep_FSTOrd41_0.tbk, _ep_FSTOrd41_0.tix, _eq.fdt, _eq.fdx, _eq.fnm, _eq.nvd, _eq.nvm, _eq.si, _eq_FSTOrd41_0.doc, _eq_FSTOrd41_0.tbk, _eq_FSTOrd41_0.tix, _er.fdt, _er.fdx, _er.fnm, _er.nvd, _er.nvm, _er.si, _er_FSTOrd41_0.doc, _er_FSTOrd41_0.tbk, _er_FSTOrd41_0.tix, _es.fdt, _es.fdx, _es.fnm, _es.nvd, _es.nvm, _es.si, _es_FSTOrd41_0.doc, _es_FSTOrd41_0.tbk, _es_FSTOrd41_0.tix, segments_2]}, {indexVersion=1394847483901,generation=3,filelist=[_en.fdt, _en.fdx, _en.fnm, _en.nvd, _en.nvm, _en.si, _en_FSTOrd41_0.doc, _en_FSTOrd41_0.tbk, _en_FSTOrd41_0.tix, _eo.cfe, _eo.cfs, _eo.si, _ep.fdt, _ep.fdx, _ep.fnm, _ep.nvd, _ep.nvm, _ep.si, _ep_FSTOrd41_0.doc, _ep_FSTOrd41_0.tbk, _ep_FSTOrd41_0.tix, _eq.fdt, _eq.fdx, _eq.fnm, _eq.nvd, _eq.nvm, _eq.si, _eq_FSTOrd41_0.doc, _eq_FSTOrd41_0.tbk, _eq_FSTOrd41_0.tix, _er.fdt, _er.fdx, _er.fnm, _er.nvd, _er.nvm, _er.si, _er_FSTOrd41_0.doc, _er_FSTOrd41_0.tbk, _er_FSTOrd41_0.tix, _es.fdt, _es.fdx, _es.fnm, _es.nvd, _es.nvm, _es.si, _es_FSTOrd41_0.doc, _es_FSTOrd41_0.tbk, _es_FSTOrd41_0.tix, _et.fdt, _et.fdx, _et.fnm, _et.nvd, _et.nvm, _et.si, _et_FSTOrd41_0.doc, _et_FSTOrd41_0.tbk, _et_FSTOrd41_0.tix, segments_3]}]>
at __randomizedtesting.SeedInfo.seed([1427B406A84AF0B2:31F0AF36D802FEB1]: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:147)
at org.apache.solr.handler.TestReplicationHandler.doTestReplicateAfterCoreReload(TestReplicationHandler.java:1184)
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:1617)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
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:359)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
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:359)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 10862 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> 2380929 T12149 oas.SolrTestCaseJ4.setUp ###Starting testNoWriter
[junit4] 2> 2380946 T12149 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2380949 T12149 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:50575
[junit4] 2> 2380950 T12149 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2380950 T12149 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2380951 T12149 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master
[junit4] 2> 2380951 T12149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/'
[junit4] 2> 2380987 T12149 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/solr.xml
[junit4] 2> 2381088 T12149 oasc.CoreContainer.<init> New CoreContainer 856480620
[junit4] 2> 2381089 T12149 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/]
[junit4] 2> 2381091 T12149 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2381091 T12149 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2381092 T12149 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2381092 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2381093 T12149 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2381093 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2381093 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2381094 T12149 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2381094 T12149 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2381106 T12149 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2381106 T12149 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2381106 T12149 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2381113 T12159 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1
[junit4] 2> 2381114 T12159 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/'
[junit4] 2> 2381167 T12159 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 2381228 T12159 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2381229 T12159 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2381235 T12159 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2381257 T12159 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2381259 T12159 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2381259 T12159 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data/
[junit4] 2> 2381260 T12159 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 2381261 T12159 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data
[junit4] 2> 2381262 T12159 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data/index/
[junit4] 2> 2381262 T12159 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 2381263 T12159 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data/index
[junit4] 2> 2381263 T12159 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=28, maxMergedSegmentMB=62.2333984375, floorSegmentMB=1.521484375, forceMergeDeletesPctAllowed=10.585613180301214, segmentsPerTier=21.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2381264 T12159 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(RateLimitedDirectoryWrapper(NRTCachingDirectory(RAMDirectory@4bda2241 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4023cbd9; maxCacheMB=0.630859375 maxMergeSizeMB=0.6357421875))),segFN=segments_1,generation=1}
[junit4] 2> 2381264 T12159 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2381265 T12159 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2381266 T12159 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2381266 T12159 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2381266 T12159 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 2381266 T12159 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 2381267 T12159 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 2381267 T12159 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2381283 T12159 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2381286 T12159 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2381287 T12159 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2381287 T12159 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@7c88e77e
[junit4] 2> 2381288 T12159 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(RateLimitedDirectoryWrapper(NRTCachingDirectory(RAMDirectory@4bda2241 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4023cbd9; maxCacheMB=0.630859375 maxMergeSizeMB=0.6357421875))),segFN=segments_1,generation=1}
[junit4] 2> 2381288 T12159 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2381288 T12159 oass.SolrIndexSearcher.<init> Opening Searcher@350a04c9[collection1] main
[junit4] 2> 2381289 T12159 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 2381289 T12159 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 2381289 T12159 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2381289 T12160 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@350a04c9[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2381290 T12149 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4] 2> 2381290 T12149 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2381302 T12149 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2381306 T12149 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:50576
[junit4] 2> 2381306 T12149 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2381307 T12149 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2381307 T12149 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave
[junit4] 2> 2381308 T12149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/'
[junit4] 2> 2381322 T12149 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/solr.xml
[junit4] 2> 2381384 T12149 oasc.CoreContainer.<init> New CoreContainer 1405774671
[junit4] 2> 2381384 T12149 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/]
[junit4] 2> 2381386 T12149 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2381387 T12149 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2381387 T12149 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2381387 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2381388 T12149 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2381388 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2381389 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2381389 T12149 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2381389 T12149 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2381399 T12149 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2381399 T12149 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2381399 T12149 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2381405 T12171 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1
[junit4] 2> 2381406 T12171 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/'
[junit4] 2> 2381459 T12171 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 2381528 T12171 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2381529 T12171 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2381535 T12171 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2381553 T12171 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2381554 T12171 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2381555 T12171 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/
[junit4] 2> 2381555 T12171 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 2381557 T12171 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data
[junit4] 2> 2381557 T12171 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index/
[junit4] 2> 2381558 T12171 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 2381559 T12171 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index
[junit4] 2> 2381559 T12171 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=28, maxMergedSegmentMB=62.2333984375, floorSegmentMB=1.521484375, forceMergeDeletesPctAllowed=10.585613180301214, segmentsPerTier=21.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2381560 T12171 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(RateLimitedDirectoryWrapper(NRTCachingDirectory(RAMDirectory@23778d38 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@518219a; maxCacheMB=0.630859375 maxMergeSizeMB=0.6357421875))),segFN=segments_1,generation=1}
[junit4] 2> 2381561 T12171 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2381562 T12171 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2381562 T12171 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2381562 T12171 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 2381562 T12171 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 2381563 T12171 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 2381563 T12171 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2381563 T12171 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2381565 T12171 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2381568 T12171 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2381569 T12171 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2381569 T12171 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@39778685
[junit4] 2> 2381570 T12171 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(RateLimitedDirectoryWrapper(NRTCachingDirectory(RAMDirectory@23778d38 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@518219a; maxCacheMB=0.630859375 maxMergeSizeMB=0.6357421875))),segFN=segments_1,generation=1}
[junit4] 2> 2381570 T12171 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2381570 T12171 oass.SolrIndexSearcher.<init> Opening Searcher@78bce450[collection1] main
[junit4] 2> 2381576 T12171 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4] 2> 2381577 T12171 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2381577 T12172 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@78bce450[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2381577 T12149 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4] 2> 2381578 T12149 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2381579 T12149 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1405774671
[junit4] 2> 2381580 T12149 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@43fe948b
[junit4] 2> 2381581 T12149 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 2381582 T12149 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 2381582 T12149 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 2381583 T12149 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 2381583 T12149 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 2381584 T12149 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 2381584 T12149 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index;done=false>>]
[junit4] 2> 2381585 T12149 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index
[junit4] 2> 2381586 T12149 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data;done=false>>]
[junit4] 2> 2381587 T12149 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data
[junit4] 2> 2381588 T12149 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 2381640 T12149 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=856480620
[junit4] 2> 2381642 T12149 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@6bea73b5
[junit4] 2> 2381642 T12149 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 2381643 T12149 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 2381643 T12149 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 2381643 T12149 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 2381644 T12149 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 2381645 T12149 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 2381645 T12149 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data;done=false>>]
[junit4] 2> 2381645 T12149 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data
[junit4] 2> 2381646 T12149 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data/index;done=false>>]
[junit4] 2> 2381646 T12149 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data/index
[junit4] 2> 2381648 T12149 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 2381700 T12149 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2381704 T12149 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:50576
[junit4] 2> 2381705 T12149 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2381705 T12149 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2381706 T12149 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave
[junit4] 2> 2381706 T12149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/'
[junit4] 2> 2381720 T12149 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/solr.xml
[junit4] 2> 2381781 T12149 oasc.CoreContainer.<init> New CoreContainer 1136310950
[junit4] 2> 2381782 T12149 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/]
[junit4] 2> 2381784 T12149 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2381784 T12149 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2381784 T12149 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2381785 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2381785 T12149 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2381786 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2381786 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2381786 T12149 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2381787 T12149 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2381796 T12149 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2381797 T12149 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2381797 T12149 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2381802 T12184 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1
[junit4] 2> 2381804 T12184 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/'
[junit4] 2> 2381859 T12184 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 2381920 T12184 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2381921 T12184 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2381927 T12184 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2381945 T12184 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2381947 T12184 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4] 2> 2381947 T12184 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/
[junit4] 2> 2381947 T12184 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 2381948 T12184 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data
[junit4] 2> 2381949 T12184 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index/
[junit4] 2> 2381950 T12184 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 2381951 T12184 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index
[junit4] 2> 2381952 T12184 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@287e8637
[junit4] 2> 2382005 T12184 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@a9d99a6; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4] 2> 2382006 T12184 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2382007 T12184 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2382007 T12184 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2382008 T12184 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 2382008 T12184 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 2382008 T12184 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 2382008 T12184 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2382009 T12184 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2382025 T12184 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2382032 T12184 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2382033 T12184 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2382035 T12184 oass.SolrIndexSearcher.<init> Opening Searcher@34427d05[collection1] main
[junit4] 2> 2382035 T12184 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4] 2> 2382036 T12184 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2382036 T12185 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@34427d05[collection1] main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 2382036 T12149 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4] 2> 2382037 T12149 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2382037 T12149 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2382041 T12149 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:50575
[junit4] 2> 2382042 T12149 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2382042 T12149 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2382043 T12149 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master
[junit4] 2> 2382043 T12149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/'
[junit4] 2> 2382080 T12149 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/solr.xml
[junit4] 2> 2382167 T12149 oasc.CoreContainer.<init> New CoreContainer 1848513723
[junit4] 2> 2382168 T12149 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/]
[junit4] 2> 2382169 T12149 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2382170 T12149 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2382170 T12149 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2382170 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2382171 T12149 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2382171 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2382172 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2382172 T12149 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2382172 T12149 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2382182 T12149 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2382183 T12149 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2382183 T12149 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2382189 T12197 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1
[junit4] 2> 2382190 T12197 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/'
[junit4] 2> 2382253 T12197 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 2382314 T12197 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2382315 T12186 oash.SnapPuller.fetchLatestIndex ERROR Master at: http://127.0.0.1:50575/solr is not available. Index fetch failed. Exception: Expected mime type application/octet-stream but got text/html. <html>
[junit4] 2> <head>
[junit4] 2> <meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/>
[junit4] 2> <title>Error 503 Server is shutting down or failed to initialize</title>
[junit4] 2> </head>
[junit4] 2> <body>
[junit4] 2> <h2>HTTP ERROR: 503</h2>
[junit4] 2> <p>Problem accessing /solr/replication. Reason:
[junit4] 2> <pre> Server is shutting down or failed to initialize</pre></p>
[junit4] 2> <hr /><i><small>Powered by Jetty://</small></i>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2> </body>
[junit4] 2> </html>
[junit4] 2>
[junit4] 2> 2382316 T12197 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2382324 T12197 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2382346 T12197 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2382348 T12197 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4] 2> 2382348 T12197 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data/
[junit4] 2> 2382349 T12197 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 2382349 T12197 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data
[junit4] 2> 2382350 T12197 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data/index/
[junit4] 2> 2382351 T12197 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 2382352 T12197 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data/index
[junit4] 2> 2382353 T12197 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@7cf2a29e
[junit4] 2> 2382361 T12197 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d927328; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4] 2> 2382361 T12197 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2382362 T12197 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2382363 T12197 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2382363 T12197 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2382363 T12197 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 2382364 T12197 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 2382364 T12197 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 2382364 T12197 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2382381 T12197 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2382388 T12197 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2382388 T12197 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2382390 T12197 oass.SolrIndexSearcher.<init> Opening Searcher@4b59d378[collection1] main
[junit4] 2> 2382391 T12197 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 2382391 T12197 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 2382391 T12197 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2382391 T12198 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4b59d378[collection1] main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 2382392 T12149 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4] 2> 2382392 T12149 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> ASYNC NEW_CORE C11807 name=collection1 org.apache.solr.core.SolrCore@5d0075ad
[junit4] 2> 2382396 T12177 C11807 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@766f3bc6
[junit4] 2> 2382399 T12177 C11807 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@a9d99a6; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4] 2> 2382400 T12177 C11807 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2382402 T12177 C11807 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[123456]} 0 8
[junit4] 2> 2382405 T12177 C11807 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2382458 T12177 C11807 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=NRTCachingDirectory(NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@a9d99a6; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=NRTCachingDirectory(NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@a9d99a6; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2}
[junit4] 2> 2382459 T12177 C11807 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 2382475 T12177 C11807 oass.SolrIndexSearcher.<init> Opening Searcher@7c7bbde1[collection1] main
[junit4] 2> 2382475 T12177 C11807 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 2382475 T12185 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7c7bbde1[collection1] main{StandardDirectoryReader(segments_2:3 _0(4.8):C1)}
[junit4] 2> 2382476 T12177 C11807 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&waitSearcher=true&version=2&commit=true&wt=javabin} {commit=} 0 71
[junit4] 2> 2382477 T12149 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1136310950
[junit4] 2> 2382478 T12149 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@5d0075ad
[junit4] 2> 2382479 T12149 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=1,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 2382481 T12149 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 2382481 T12149 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 2382481 T12149 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 2382483 T12149 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 2382484 T12149 oasc.CachingDirectoryFactory.close Closing NRTCachingDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 2382485 T12149 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data;done=false>>]
[junit4] 2> 2382485 T12149 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data
[junit4] 2> 2382485 T12149 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index;done=false>>]
[junit4] 2> 2382486 T12149 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index
[junit4] 2> 2382487 T12149 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 2382539 T12149 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2382543 T12149 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:50576
[junit4] 2> 2382543 T12149 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2382544 T12149 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2382544 T12149 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave
[junit4] 2> 2382545 T12149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/'
[junit4] 2> 2382581 T12149 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/solr.xml
[junit4] 2> 2382672 T12149 oasc.CoreContainer.<init> New CoreContainer 1924820223
[junit4] 2> 2382673 T12149 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/]
[junit4] 2> 2382675 T12149 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2382675 T12149 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2382675 T12149 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2382676 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2382676 T12149 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2382677 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2382677 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2382677 T12149 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2382678 T12149 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2382688 T12149 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2382688 T12149 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2382688 T12149 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2382694 T12209 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1
[junit4] 2> 2382695 T12209 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/'
[junit4] 2> 2382748 T12209 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 2382808 T12209 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2382809 T12209 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2382815 T12209 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2382838 T12209 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2382839 T12209 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4] 2> 2382840 T12209 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/
[junit4] 2> 2382840 T12209 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 2382840 T12209 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data
[junit4] 2> 2382841 T12209 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index/
[junit4] 2> 2382842 T12209 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2382842 T12209 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2382843 T12209 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 2382843 T12209 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 2382843 T12209 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 2382843 T12209 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2382844 T12209 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2382860 T12209 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2382863 T12209 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2382863 T12209 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2382864 T12209 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index
[junit4] 2> 2382867 T12209 oass.SolrIndexSearcher.<init> Opening Searcher@368d5858[collection1] main
[junit4] 2> 2382868 T12209 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4] 2> 2382868 T12209 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2382868 T12210 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@368d5858[collection1] main{StandardDirectoryReader(segments_2:3 _0(4.8):C1)}
[junit4] 2> 2382868 T12149 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4] 2> 2382869 T12149 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2382873 T12213 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 2382873 T12213 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> ASYNC NEW_CORE C11808 name=collection1 org.apache.solr.core.SolrCore@190e37bb
[junit4] 2> 2382874 T12191 C11808 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=0
[junit4] 2> ASYNC NEW_CORE C11809 name=collection1 org.apache.solr.core.SolrCore@51424188
[junit4] 2> 2382875 T12202 C11809 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=fetchindex&masterUrl=http://127.0.0.1:50575/solr/replication&wait=true} status=0 QTime=3
[junit4] 2> 2382877 T12149 oas.SolrTestCaseJ4.tearDown ###Ending testNoWriter
[junit4] 2> 2382878 T12149 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1848513723
[junit4] 2> 2382879 T12149 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@190e37bb
[junit4] 2> 2382879 T12149 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 2382880 T12149 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 2382880 T12149 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 2382881 T12149 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 2382881 T12149 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 2382882 T12149 oasc.CachingDirectoryFactory.close Closing NRTCachingDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 2382883 T12149 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data;done=false>>]
[junit4] 2> 2382883 T12149 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data
[junit4] 2> 2382884 T12149 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data/index;done=false>>]
[junit4] 2> 2382884 T12149 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843619/master/collection1/data/index
[junit4] 2> 2382885 T12149 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 2382937 T12149 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1924820223
[junit4] 2> 2382938 T12149 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@51424188
[junit4] 2> 2382939 T12149 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 2382939 T12149 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 2382940 T12149 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 2382940 T12149 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 2382941 T12149 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 2382942 T12149 oasc.CachingDirectoryFactory.close Closing NRTCachingDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 2382943 T12149 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data;done=false>>]
[junit4] 2> 2382943 T12149 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data
[junit4] 2> 2382944 T12149 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index;done=false>>]
[junit4] 2> 2382945 T12149 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846843980/slave/collection1/data/index
[junit4] 2> 2382946 T12149 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 2383023 T12149 oas.SolrTestCaseJ4.setUp ###Starting doTestRepeater
[junit4] 2> 2383038 T12149 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2383041 T12149 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:50581
[junit4] 2> 2383042 T12149 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2383042 T12149 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2383043 T12149 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846845712/master
[junit4] 2> 2383043 T12149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846845712/master/'
[junit4] 2> 2383080 T12149 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846845712/master/solr.xml
[junit4] 2> 2383181 T12149 oasc.CoreContainer.<init> New CoreContainer 64775635
[junit4] 2> 2383181 T12149 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846845712/master/]
[junit4] 2> 2383183 T12149 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2383183 T12149 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2383184 T12149 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2383184 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2383185 T12149 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2383185 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2383185 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2383186 T12149 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2383186 T12149 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2383196 T12149 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2383196 T12149 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2383197 T12149 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2383203 T12224 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846845712/master/collection1
[junit4] 2> 2383204 T12224 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846845712/master/collection1/'
[junit4] 2> 2383256 T12224 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 2383316 T12224 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2383317 T12224 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2383323 T12224 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2383345 T12224 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2383347 T12224 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2383347 T12224 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846845712/master/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846845712/master/collection1/data/
[junit4] 2> 2383347 T12224 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 2383349 T12224 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846845712/master/collection1/data
[junit4] 2> 2383350 T12224 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846845712/master/collection1/data/index/
[junit4] 2> 2383350 T12224 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846845712/master/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 2383351 T12224 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846845712/master/collection1/data/index
[junit4] 2> 2383351 T12224 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=28, maxMergedSegmentMB=62.2333984375, floorSegmentMB=1.521484375, forceMergeDeletesPctAllowed=10.585613180301214, segmentsPerTier=21.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2383352 T12224 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(RateLimitedDirectoryWrapper(NRTCachingDirectory(RAMDirectory@293f68c7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7aee97b5; maxCacheMB=0.630859375 maxMergeSizeMB=0.6357421875))),segFN=segments_1,generation=1}
[junit4] 2> 2383352 T12224 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2383353 T12224 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2383354 T12224 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2383354 T12224 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2383354 T12224 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 2383355 T12224 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 2383355 T12224 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 2383355 T12224 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2383371 T12224 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2383374 T12224 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2383375 T12224 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2383375 T12224 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@570951b
[junit4] 2> 2383376 T12224 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(RateLimitedDirectoryWrapper(NRTCachingDirectory(RAMDirectory@293f68c7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7aee97b5; maxCacheMB=0.630859375 maxMergeSizeMB=0.6357421875))),segFN=segments_1,generation=1}
[junit4] 2> 2383376 T12224 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2383376 T12224 oass.SolrIndexSearcher.<init> Opening Searcher@760da9c8[collection1] main
[junit4] 2> 2383377 T12224 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 2383377 T12224 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 2383377 T12224 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2383377 T12225 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@760da9c8[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2383378 T12149 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4] 2> 2383378 T12149 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2383390 T12149 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2383393 T12149 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:50582
[junit4] 2> 2383394 T12149 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2383394 T12149 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2383395 T12149 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846846068/slave
[junit4] 2> 2383395 T12149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846846068/slave/'
[junit4] 2> 2383409 T12149 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846846068/slave/solr.xml
[junit4] 2> 2383471 T12149 oasc.CoreContainer.<init> New CoreContainer 1620110586
[junit4] 2> 2383472 T12149 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846846068/slave/]
[junit4] 2> 2383473 T12149 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2383474 T12149 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2383474 T12149 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2383474 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2383475 T12149 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2383475 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2383476 T12149 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2383476 T12149 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2383476 T12149 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2383486 T12149 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2383486 T12149 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2383487 T12149 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2383492 T12236 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846846068/slave/collection1
[junit4] 2> 2383494 T12236 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846846068/slave/collection1/'
[junit4] 2> 2383545 T12236 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 2383614 T12236 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2383615 T12236 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2383621 T12236 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2383639 T12236 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2383641 T12236 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2383641 T12236 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846846068/slave/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846846068/slave/collection1/data/
[junit4] 2> 2383641 T12236 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 2383643 T12236 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846846068/slave/collection1/data
[junit4] 2> 2383644 T12236 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846846068/slave/collection1/data/index/
[junit4] 2> 2383644 T12236 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846846068/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 2383645 T12236 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846846068/slave/collection1/data/index
[junit4] 2> 2383646 T12236 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=28, maxMergedSegmentMB=62.2333984375, floorSegmentMB=1.521484375, forceMergeDeletesPctAllowed=10.585613180301214, segmentsPerTier=21.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2383647 T12236 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(RateLimitedDirectoryWrapper(NRTCachingDirectory(RAMDirectory@3675e2bd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3093819f; maxCacheMB=0.630859375 maxMergeSizeMB=0.6357421875))),segFN=segments_1,generation=1}
[junit4] 2> 2383647 T12236 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2383648 T12236 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2383648 T12236 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2383648 T12236 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 2383649 T12236 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 2383649 T12236 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 2383649 T12236 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2383650 T12236 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2383652 T12236 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2383654 T12236 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2383655 T12236 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2383655 T12236 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@11d6694a
[junit4] 2> 2383656 T12236 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(RateLimitedDirectoryWrapper(NRTCachingDirectory(RAMDirectory@3675e2bd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3093819f; maxCacheMB=0.630859375 maxMergeSizeMB=0.6357421875))),segFN=segments_1,generation=1}
[junit4] 2> 2383656 T12236 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2383656 T12236 oass.SolrIndexSearcher.<init> Opening Searcher@4e88a82[collection1] main
[junit4] 2> 2383657 T12236 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4] 2> 2383657 T12236 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2383657 T12237 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4e88a82[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2383658 T12149 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4] 2> 2383658 T12149 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2383662 T12149 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1620110586
[junit4] 2> 2383664 T12149 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@49fa2bfa
[junit4] 2> 2383664 T12149 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 2383665 T12149 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 2383665 T12149 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 2383666 T12149 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 2383666 T12149 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 2383667 T12149 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 2383667 T12149 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846846068/slave/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846846068/slave/collection1/data;done=false>>]
[junit4] 2> 2383668 T12149 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394846846068/slave/collection1/data
[junit4] 2> 2383668 T12149 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-
[...truncated too long message...]
e /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394847529289/master/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394847529289/master/collection1/data;done=false>>]
[junit4] 2> 3067735 T12149 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394847529289/master/collection1/data
[junit4] 2> 3067736 T12149 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394847529289/master/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394847529289/master/collection1/data/index;done=false>>]
[junit4] 2> 3067736 T12149 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394847529289/master/collection1/data/index
[junit4] 2> 3067738 T12149 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 3067790 T12149 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=733227724
[junit4] 2> 3067792 T12149 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@58b2aa8
[junit4] 2> 3067792 T12149 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 3067793 T12149 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 3067793 T12149 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 3067794 T12149 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 3067795 T12149 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 3067795 T12149 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 3067796 T12149 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394847529676/slave/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394847529676/slave/collection1/data;done=false>>]
[junit4] 2> 3067796 T12149 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394847529676/slave/collection1/data
[junit4] 2> 3067796 T12149 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394847529676/slave/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394847529676/slave/collection1/data/index;done=false>>]
[junit4] 2> 3067797 T12149 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394847529676/slave/collection1/data/index
[junit4] 2> 3067800 T12149 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 3067864 T12149 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 686945 T12148 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> 3071883 T13146 oash.SnapPuller.fetchLatestIndex ERROR Master at: http://127.0.0.1:36527/solr is not available. Index fetch failed. Exception: IOException occured when talking to server at: http://127.0.0.1:36527/solr
[junit4] 2> 3071884 T13146 oasc.SolrException.log ERROR SnapPull failed :org.apache.lucene.store.AlreadyClosedException: Already closed
[junit4] 2> at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:340)
[junit4] 2> at org.apache.solr.handler.ReplicationHandler.loadReplicationProperties(ReplicationHandler.java:812)
[junit4] 2> at org.apache.solr.handler.SnapPuller.logReplicationTimeAndConfFiles(SnapPuller.java:566)
[junit4] 2> at org.apache.solr.handler.SnapPuller.fetchLatestIndex(SnapPuller.java:508)
[junit4] 2> at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:323)
[junit4] 2> at org.apache.solr.handler.ReplicationHandler$1.run(ReplicationHandler.java:224)
[junit4] 2>
[junit4] 2> NOTE: test params are: codec=Lucene46: {id=FSTOrd41, newname=FSTOrd41, name=FSTOrd41}, docValues:{}, sim=DefaultSimilarity, locale=es, timezone=Pacific/Fakaofo
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=257660160,total=520355840
[junit4] 2> NOTE: All tests run in this JVM: [BasicDistributedZk2Test, TestStressRecovery, DocValuesMissingTest, TestBinaryField, DirectSolrSpellCheckerTest, TestDistributedSearch, HardAutoCommitTest, TestCollationField, MultiTermTest, TestIndexSearcher, TestImplicitCoreProperties, TestSolrQueryParserDefaultOperatorResource, TestCollapseQParserPlugin, BadIndexSchemaTest, TestQuerySenderNoQuery, ChangedSchemaMergeTest, BlockDirectoryTest, TestNumberUtils, TestRangeQuery, HdfsUnloadDistributedZkTest, TestFieldTypeCollectionResource, PluginInfoTest, TestDFRSimilarityFactory, SolrRequestParserTest, HdfsBasicDistributedZk2Test, SpellCheckComponentTest, PrimUtilsTest, NumericFieldsTest, SolrCoreCheckLockOnStartupTest, TestPhraseSuggestions, TestDynamicFieldResource, TestShardHandlerFactory, TestAtomicUpdateErrorCases, TestFastOutputStream, TestStandardQParsers, ChaosMonkeySafeLeaderTest, SignatureUpdateProcessorFactoryTest, TestFastLRUCache, ConvertedLegacyTest, TestFieldTypeResource, TestQueryTypes, TimeZoneUtilsTest, DirectSolrConnectionTest, SolrIndexConfigTest, TestBlendedInfixSuggestions, TestRecoveryHdfs, TestPartialUpdateDeduplication, CurrencyFieldXmlFileTest, TestReloadAndDeleteDocs, FileUtilsTest, TestSolrQueryParserResource, CoreAdminCreateDiscoverTest, PreAnalyzedUpdateProcessorTest, TestDistributedMissingSort, TestFieldCollectionResource, DefaultValueUpdateProcessorTest, ConnectionManagerTest, TestSolr4Spatial, TestSchemaSimilarityResource, TermVectorComponentDistributedTest, OutputWriterTest, TestZkChroot, TestCloudManagedSchema, TestSimpleQParserPlugin, DirectUpdateHandlerTest, DocValuesMultiTest, DebugComponentTest, ZkNodePropsTest, TestMultiCoreConfBootstrap, RequiredFieldsTest, TestDefaultSimilarityFactory, SuggesterWFSTTest, DistanceFunctionTest, CurrencyFieldOpenExchangeTest, StandardRequestHandlerTest, TestFileDictionaryLookup, StressHdfsTest, ShardRoutingCustomTest, TestIBSimilarityFactory, TestXIncludeConfig, TestLazyCores, AlternateDirectoryTest, TestDistribDocBasedVersion, TestRandomMergePolicy, ZkSolrClientTest, HdfsCollectionsAPIDistributedZkTest, MinimalSchemaTest, TestCSVResponseWriter, TestUtils, TestReload, CollectionsAPIDistributedZkTest, OpenCloseCoreStressTest, OverseerTest, LeaderElectionIntegrationTest, ShardRoutingTest, BasicZkTest, FullSolrCloudDistribCmdsTest, TestReplicationHandler]
[junit4] Completed on J1 in 691.02s, 14 tests, 1 failure <<< FAILURES!
[...truncated 404 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:474: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:447: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:45: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/common-build.xml:490: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:1276: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:908: There were test failures: 369 suites, 1581 tests, 1 failure, 35 ignored (7 assumptions)
Total time: 132 minutes 46 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-NightlyTests-4.x - Build # 538 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-4.x/538/
1 tests failed.
REGRESSION: org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.testDistribSearch
Error Message:
Error executing query
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: Error executing query
at __randomizedtesting.SeedInfo.seed([25E6E56BD39ADBB3:A4006B73A4C5BB8F]:0)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:100)
at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.compareResults(AbstractFullDistribZkTestBase.java:1339)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.compareResults(AbstractFullDistribZkTestBase.java:1291)
at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.testIndexingBatchPerRequestWithHttpSolrServer(FullSolrCloudDistribCmdsTest.java:415)
at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.doTest(FullSolrCloudDistribCmdsTest.java:145)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:870)
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:1617)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
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:359)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
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:359)
at java.lang.Thread.run(Thread.java:724)
Caused by: org.apache.http.ParseException: Invalid content type:
at org.apache.http.entity.ContentType.parse(ContentType.java:233)
at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:450)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:203)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91)
... 45 more
Build Log:
[...truncated 10419 lines...]
[junit4] Suite: org.apache.solr.cloud.FullSolrCloudDistribCmdsTest
[junit4] 2> 848017 T5647 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 848021 T5647 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-FullSolrCloudDistribCmdsTest-1394948247975
[junit4] 2> 848022 T5647 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 848023 T5648 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 848123 T5647 oasc.ZkTestServer.run start zk server on port:56118
[junit4] 2> 848124 T5647 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 848131 T5654 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16935a7a name:ZooKeeperConnection Watcher:127.0.0.1:56118 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 848132 T5647 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 848132 T5647 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 848137 T5647 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 848150 T5656 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a067ffa name:ZooKeeperConnection Watcher:127.0.0.1:56118/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 848151 T5647 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 848151 T5647 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 848156 T5647 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 848164 T5647 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 848166 T5647 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 848169 T5647 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 848170 T5647 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 848180 T5647 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 848181 T5647 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 848290 T5647 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 848290 T5647 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 848301 T5647 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 848302 T5647 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 848306 T5647 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 848306 T5647 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 848310 T5647 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 848311 T5647 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 848314 T5647 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 848315 T5647 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 848321 T5647 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 848321 T5647 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 848325 T5647 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 848325 T5647 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 848329 T5647 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 848329 T5647 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 848332 T5647 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 848333 T5647 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 849337 T5647 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 849341 T5647 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:56121
[junit4] 2> 849341 T5647 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 849341 T5647 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 849342 T5647 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394948248297
[junit4] 2> 849342 T5647 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394948248297/'
[junit4] 2> 849369 T5647 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394948248297/solr.xml
[junit4] 2> 849453 T5647 oasc.CoreContainer.<init> New CoreContainer 594536538
[junit4] 2> 849454 T5647 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394948248297/]
[junit4] 2> 849455 T5647 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 849456 T5647 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 849456 T5647 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 849456 T5647 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 849456 T5647 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 849457 T5647 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 849457 T5647 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 849457 T5647 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 849457 T5647 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 849458 T5647 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 849458 T5647 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 849459 T5647 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 849459 T5647 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56118/solr
[junit4] 2> 849459 T5647 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 849460 T5647 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 849463 T5667 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ff7ee3 name:ZooKeeperConnection Watcher:127.0.0.1:56118 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 849464 T5647 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 849467 T5647 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 849469 T5669 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@509d56cd name:ZooKeeperConnection Watcher:127.0.0.1:56118/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 849469 T5647 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 849483 T5647 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 849487 T5647 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 849497 T5647 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 849499 T5647 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56121_
[junit4] 2> 849500 T5647 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56121_
[junit4] 2> 849503 T5647 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 849505 T5647 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 849509 T5647 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:56121_
[junit4] 2> 849510 T5647 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 849512 T5647 oasc.Overseer.start Overseer (id=91419328379748355-127.0.0.1:56121_-n_0000000000) starting
[junit4] 2> 849516 T5647 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 849526 T5671 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 849527 T5647 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 849527 T5671 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 849530 T5647 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 849537 T5647 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 849540 T5670 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 849545 T5672 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 849545 T5672 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 849547 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 849547 T5672 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 849548 T5670 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 849548 T5670 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:56121",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:56121_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 849549 T5670 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 849549 T5670 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 849557 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 849558 T5669 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 850548 T5672 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 850548 T5672 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394948248297/collection1
[junit4] 2> 850548 T5672 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 850549 T5672 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 850550 T5672 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 850551 T5672 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 850551 T5672 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394948248297/collection1/'
[junit4] 2> 850552 T5672 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394948248297/collection1/lib/README' to classloader
[junit4] 2> 850553 T5672 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394948248297/collection1/lib/classes/' to classloader
[junit4] 2> 850554 T5672 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394948248297/collection1/lib/.svn/' to classloader
[junit4] 2> 850629 T5672 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 850704 T5672 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 850805 T5672 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 850818 T5672 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 851405 T5672 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 851409 T5672 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 851411 T5672 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 851417 T5672 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 851452 T5672 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 851452 T5672 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394948248297/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394948247974/control/data/
[junit4] 2> 851453 T5672 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@67041ec7
[junit4] 2> 851454 T5672 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394948247974/control/data
[junit4] 2> 851454 T5672 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394948247974/control/data/index/
[junit4] 2> 851454 T5672 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394948247974/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 851455 T5672 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394948247974/control/data/index
[junit4] 2> 851455 T5672 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=7, maxMergeAtOnceExplicit=2, maxMergedSegmentMB=66.853515625, floorSegmentMB=1.0546875, forceMergeDeletesPctAllowed=14.929764705580716, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 851457 T5672 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@2b4f6e59 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@16fe870a; maxCacheMB=0.8095703125 maxMergeSizeMB=0.5419921875)),segFN=segments_1,generation=1}
[junit4] 2> 851457 T5672 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 851462 T5672 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 851462 T5672 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 851463 T5672 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 851463 T5672 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 851463 T5672 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 851463 T5672 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 851464 T5672 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 851464 T5672 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 851465 T5672 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 851465 T5672 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 851466 T5672 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 851466 T5672 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 851467 T5672 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 851467 T5672 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 851468 T5672 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 851468 T5672 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 851487 T5672 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 851493 T5672 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 851494 T5672 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 851495 T5672 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=20.861328125, floorSegmentMB=1.62109375, forceMergeDeletesPctAllowed=22.138564378072537, segmentsPerTier=16.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 851495 T5672 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@2b4f6e59 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@16fe870a; maxCacheMB=0.8095703125 maxMergeSizeMB=0.5419921875)),segFN=segments_1,generation=1}
[junit4] 2> 851496 T5672 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 851496 T5672 oass.SolrIndexSearcher.<init> Opening Searcher@1535d274[collection1] main
[junit4] 2> 851501 T5673 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1535d274[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 851504 T5672 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 851504 T5647 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4] 2> 851505 T5647 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 851504 T5676 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56121 collection:control_collection shard:shard1
[junit4] 2> 851506 T5647 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 851507 T5676 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 851509 T5678 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b66672b name:ZooKeeperConnection Watcher:127.0.0.1:56118/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 851509 T5647 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 851512 T5647 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 851527 T5647 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 851529 T5676 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 851539 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 851540 T5676 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 851540 T5676 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C252 name=collection1 org.apache.solr.core.SolrCore@9e23baf url=http://127.0.0.1:56121/collection1 node=127.0.0.1:56121_ C252_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:56121, core=collection1, node_name=127.0.0.1:56121_}
[junit4] 2> 851540 T5676 C252 P56121 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:56121/collection1/
[junit4] 2> 851541 T5676 C252 P56121 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 851541 T5670 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 851541 T5676 C252 P56121 oasc.SyncStrategy.syncToMe http://127.0.0.1:56121/collection1/ has no replicas
[junit4] 2> 851541 T5676 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:56121/collection1/ shard1
[junit4] 2> 851542 T5676 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 851545 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 851546 T5669 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 851546 T5678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 851554 T5670 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 851558 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 851661 T5669 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 851661 T5678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 851707 T5676 oasc.ZkController.register We are http://127.0.0.1:56121/collection1/ and leader is http://127.0.0.1:56121/collection1/
[junit4] 2> 851707 T5676 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56121
[junit4] 2> 851707 T5676 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 851707 T5676 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 851708 T5676 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 851709 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 851710 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 851710 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 851710 T5676 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 851712 T5670 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 851713 T5670 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:56121",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:56121_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 851717 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 851822 T5669 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 851822 T5678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 852465 T5647 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 852467 T5647 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 852469 T5647 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:56125
[junit4] 2> 852469 T5647 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 852470 T5647 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 852470 T5647 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394948251480
[junit4] 2> 852470 T5647 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394948251480/'
[junit4] 2> 852497 T5647 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394948251480/solr.xml
[junit4] 2> 852563 T5647 oasc.CoreContainer.<init> New CoreContainer 1638079274
[junit4] 2> 852564 T5647 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394948251480/]
[junit4] 2> 852565 T5647 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 852565 T5647 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 852565 T5647 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 852566 T5647 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 852566 T5647 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 852566 T5647 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 852566 T5647 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 852567 T5647 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 852567 T5647 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 852567 T5647 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 852568 T5647 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 852568 T5647 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 852568 T5647 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56118/solr
[junit4] 2> 852569 T5647 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 852569 T5647 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 852572 T5689 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b4c947a name:ZooKeeperConnection Watcher:127.0.0.1:56118 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 852573 T5647 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 852576 T5647 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 852619 T5691 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5494bafb name:ZooKeeperConnection Watcher:127.0.0.1:56118/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 852619 T5647 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 852625 T5647 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 853628 T5647 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56125_
[junit4] 2> 853631 T5647 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56125_
[junit4] 2> 853635 T5691 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 853635 T5669 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 853635 T5678 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 853655 T5692 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 853655 T5692 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 853657 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 853657 T5692 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 853657 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 853658 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 853659 T5670 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 853660 T5670 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:56125",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:56125_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 853660 T5670 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 853661 T5670 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 853664 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 853673 T5691 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 853673 T5669 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 853673 T5678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 854658 T5692 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 854658 T5692 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394948251480/collection1
[junit4] 2> 854658 T5692 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 854659 T5692 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 854659 T5692 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 854661 T5692 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 854661 T5692 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394948251480/collection1/'
[junit4] 2> 854662 T5692 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394948251480/collection1/lib/classes/' to classloader
[junit4] 2> 854663 T5692 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394948251480/collection1/lib/.svn/' to classloader
[junit4] 2> 854663 T5692 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394948251480/collection1/lib/README' to classloader
[junit4] 2> 854746 T5692 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 854816 T5692 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 854918 T5692 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 854930 T5692 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 855512 T5692 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 855516 T5692 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 855518 T5692 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 855524 T5692 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 855558 T5692 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 855559 T5692 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394948251480/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394948247974/jetty1/
[junit4] 2> 855559 T5692 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@67041ec7
[junit4] 2> 855560 T5692 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394948247974/jetty1
[junit4] 2> 855560 T5692 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394948247974/jetty1/index/
[junit4] 2> 855561 T5692 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394948247974/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 855562 T5692 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394948247974/jetty1/index
[junit4] 2> 855562 T5692 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=7, maxMergeAtOnceExplicit=2, maxMergedSegmentMB=66.853515625, floorSegmentMB=1.0546875, forceMergeDeletesPctAllowed=14.929764705580716, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 855563 T5692 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@2b2471bb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@244ff5d9; maxCacheMB=0.8095703125 maxMergeSizeMB=0.5419921875)),segFN=segments_1,generation=1}
[junit4] 2> 855563 T5692 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 855570 T5692 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 855570 T5692 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 855571 T5692 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 855571 T5692 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 855571 T5692 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 855571 T5692 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 855572 T5692 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 855573 T5692 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 855573 T5692 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 855574 T5692 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 855575 T5692 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 855575 T5692 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 855575 T5692 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 855576 T5692 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 855577 T5692 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 855578 T5692 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 855595 T5692 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 855600 T5692 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 855600 T5692 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 855601 T5692 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=20.861328125, floorSegmentMB=1.62109375, forceMergeDeletesPctAllowed=22.138564378072537, segmentsPerTier=16.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 855602 T5692 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@2b2471bb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@244ff5d9; maxCacheMB=0.8095703125 maxMergeSizeMB=0.5419921875)),segFN=segments_1,generation=1}
[junit4] 2> 855602 T5692 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 855603 T5692 oass.SolrIndexSearcher.<init> Opening Searcher@389efc4a[collection1] main
[junit4] 2> 855609 T5693 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@389efc4a[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 855613 T5692 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 855614 T5647 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4] 2> 855614 T5647 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 855614 T5696 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56125 collection:collection1 shard:shard1
[junit4] 2> 855616 T5696 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 855647 T5696 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 855661 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 855662 T5696 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 855662 T5696 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C253 name=collection1 org.apache.solr.core.SolrCore@54bb0c1c url=http://127.0.0.1:56125/collection1 node=127.0.0.1:56125_ C253_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:56125, core=collection1, node_name=127.0.0.1:56125_}
[junit4] 2> 855662 T5696 C253 P56125 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:56125/collection1/
[junit4] 2> 855663 T5696 C253 P56125 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 855663 T5696 C253 P56125 oasc.SyncStrategy.syncToMe http://127.0.0.1:56125/collection1/ has no replicas
[junit4] 2> 855663 T5696 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:56125/collection1/ shard1
[junit4] 2> 855663 T5670 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 855663 T5696 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 855668 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 855669 T5669 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 855669 T5678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 855669 T5691 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 855674 T5670 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 855677 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 855782 T5691 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 855782 T5669 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 855782 T5678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 855825 T5696 oasc.ZkController.register We are http://127.0.0.1:56125/collection1/ and leader is http://127.0.0.1:56125/collection1/
[junit4] 2> 855825 T5696 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56125
[junit4] 2> 855825 T5696 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 855826 T5696 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 855826 T5696 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 855828 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 855828 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 855828 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 855828 T5696 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 855830 T5670 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 855831 T5670 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:56125",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:56125_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 855834 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 855938 T5678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 855938 T5691 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 855938 T5669 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 856531 T5647 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 856532 T5647 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 856535 T5647 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:33329
[junit4] 2> 856535 T5647 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 856535 T5647 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 856536 T5647 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394948255568
[junit4] 2> 856536 T5647 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394948255568/'
[junit4] 2> 856562 T5647 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394948255568/solr.xml
[junit4] 2> 856625 T5647 oasc.CoreContainer.<init> New CoreContainer 820808466
[junit4] 2> 856625 T5647 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394948255568/]
[junit4] 2> 856626 T5647 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 856627 T5647 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 856627 T5647 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 856627 T5647 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 856627 T5647 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 856628 T5647 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 856628 T5647 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 856628 T5647 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 856628 T5647 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 856629 T5647 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 856629 T5647 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 856630 T5647 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 856630 T5647 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56118/solr
[junit4] 2> 856630 T5647 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 856631 T5647 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 856634 T5707 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@799e63d5 name:ZooKeeperConnection Watcher:127.0.0.1:56118 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 856635 T5647 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 856649 T5647 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 856652 T5709 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4943d8e5 name:ZooKeeperConnection Watcher:127.0.0.1:56118/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 856652 T5647 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 856658 T5647 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 857661 T5647 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33329_
[junit4] 2> 857663 T5647 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:33329_
[junit4] 2> 857667 T5669 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 857667 T5678 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 857667 T5709 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 857667 T5691 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 857687 T5710 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 857688 T5710 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 857689 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 857689 T5710 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 857689 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 857690 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 857690 T5670 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 857691 T5670 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:33329",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:33329_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 857691 T5670 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 857691 T5670 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 857700 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 857702 T5709 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 857702 T5691 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 857702 T5678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 857702 T5669 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 858690 T5710 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 858690 T5710 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394948255568/collection1
[junit4] 2> 858690 T5710 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 858691 T5710 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 858692 T5710 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 858693 T5710 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 858693 T5710 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394948255568/collection1/'
[junit4] 2> 858694 T5710 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394948255568/collection1/lib/README' to classloader
[junit4] 2> 858695 T5710 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394948255568/collection1/lib/.svn/' to classloader
[junit4] 2> 858696 T5710 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394948255568/collection1/lib/classes/' to classloader
[junit4] 2> 858768 T5710 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 858847 T5710 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 858949 T5710 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 858962 T5710 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 859536 T5710 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 859540 T5710 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 859543 T5710 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 859548 T5710 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 859581 T5710 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 859581 T5710 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394948255568/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394948247974/jetty2/
[junit4] 2> 859581 T5710 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@67041ec7
[junit4] 2> 859583 T5710 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394948247974/jetty2
[junit4] 2> 859583 T5710 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394948247974/jetty2/index/
[junit4] 2> 859584 T5710 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394948247974/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 859584 T5710 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394948247974/jetty2/index
[junit4] 2> 859585 T5710 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=7, maxMergeAtOnceExplicit=2, maxMergedSegmentMB=66.853515625, floorSegmentMB=1.0546875, forceMergeDeletesPctAllowed=14.929764705580716, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 859586 T5710 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@4f233c96 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@18f8df69; maxCacheMB=0.8095703125 maxMergeSizeMB=0.5419921875)),segFN=segments_1,generation=1}
[junit4] 2> 859586 T5710 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 859593 T5710 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 859593 T5710 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 859593 T5710 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 859594 T5710 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 859594 T5710 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 859594 T5710 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 859595 T5710 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 859595 T5710 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 859595 T5710 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 859596 T5710 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 859597 T5710 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 859597 T5710 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 859598 T5710 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 859599 T5710 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 859599 T5710 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 859600 T5710 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 859617 T5710 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 859622 T5710 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 859623 T5710 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 859624 T5710 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=20.861328125, floorSegmentMB=1.62109375, forceMergeDeletesPctAllowed=22.138564378072537, segmentsPerTier=16.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 859624 T5710 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@4f233c96 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@18f8df69; maxCacheMB=0.8095703125 maxMergeSizeMB=0.5419921875)),segFN=segments_1,generation=1}
[junit4] 2> 859625 T5710 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 859625 T5710 oass.SolrIndexSearcher.<init> Opening Searcher@44cdb5a2[collection1] main
[junit4] 2> 859631 T5711 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@44cdb5a2[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 859635 T5710 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 859635 T5647 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4] 2> 859636 T5647 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 859635 T5714 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:33329 collection:collection1 shard:shard3
[junit4] 2> 859637 T5714 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 859658 T5714 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
[junit4] 2> 859661 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 859661 T5714 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 859662 T5714 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C254 name=collection1 org.apache.solr.core.SolrCore@4f46eb9f url=http://127.0.0.1:33329/collection1 node=127.0.0.1:33329_ C254_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:33329, core=collection1, node_name=127.0.0.1:33329_}
[junit4] 2> 859662 T5714 C254 P33329 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:33329/collection1/
[junit4] 2> 859662 T5714 C254 P33329 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 859662 T5714 C254 P33329 oasc.SyncStrategy.syncToMe http://127.0.0.1:33329/collection1/ has no replicas
[junit4] 2> 859663 T5670 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 859663 T5714 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:33329/collection1/ shard3
[junit4] 2> 859663 T5714 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 859667 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 859669 T5678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 859669 T5709 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 859669 T5669 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 859669 T5691 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 859674 T5670 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 859678 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 859782 T5669 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 859782 T5678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 859782 T5691 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 859782 T5709 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 859826 T5714 oasc.ZkController.register We are http://127.0.0.1:33329/collection1/ and leader is http://127.0.0.1:33329/collection1/
[junit4] 2> 859826 T5714 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:33329
[junit4] 2> 859826 T5714 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 859826 T5714 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 859826 T5714 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 859829 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 859829 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 859830 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 859832 T5670 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 859832 T5714 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 859833 T5670 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:33329",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:33329_",
[junit4] 2> "shard":"shard3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 859836 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 859939 T5669 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 859939 T5709 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 859939 T5691 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 859939 T5678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 860520 T5647 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 860521 T5647 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 860523 T5647 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:14175
[junit4] 2> 860524 T5647 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 860524 T5647 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 860524 T5647 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394948259589
[junit4] 2> 860525 T5647 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394948259589/'
[junit4] 2> 860551 T5647 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394948259589/solr.xml
[junit4] 2> 860615 T5647 oasc.CoreContainer.<init> New CoreContainer 1884247279
[junit4] 2> 860615 T5647 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394948259589/]
[junit4] 2> 860616 T5647 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 860617 T5647 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 860617 T5647 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 860617 T5647 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 860618 T5647 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 860618 T5647 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 860618 T5647 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 860618 T5647 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 860619 T5647 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 860619 T5647 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 860619 T5647 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 860620 T5647 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 860620 T5647 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56118/solr
[junit4] 2> 860620 T5647 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 860621 T5647 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 860624 T5725 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@68515083 name:ZooKeeperConnection Watcher:127.0.0.1:56118 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 860624 T5647 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 860638 T5647 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 860640 T5727 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e5920f0 name:ZooKeeperConnection Watcher:127.0.0.1:56118/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 860640 T5647 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 860644 T5647 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 861646 T5647 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:14175_
[junit4] 2> 861648 T5647 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:14175_
[junit4] 2> 861652 T5727 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 861652 T5669 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 861652 T5691 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 861652 T5709 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 861652 T5678 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 861667 T5728 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 861667 T5728 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 861668 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 861669 T5728 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 861669 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 861669 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 861670 T5670 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 861671 T5670 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:14175",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:14175_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 861671 T5670 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 861671 T5670 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 861674 T5669 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 861683 T5709 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 861683 T5678 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 861683 T5669 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 861683 T5727 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 861683 T5691 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 862671 T5728 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 862671 T5728 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394948259589/collection1
[junit4] 2> 862671 T5728 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 862672 T5728 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 862673 T5728 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 862674 T5728 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 862674 T5728 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394948259589/collection1/'
[junit4] 2> 862676 T5728 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394948259589/collection1/lib/.svn/' to classloader
[junit4] 2> 862677 T5728 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394948259589/collection1/lib/README' to classloader
[junit4] 2> 862678 T5728 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394948259589/collection1/lib/classes/' to classloader
[junit4] 2> 862749 T5728 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 862819 T5728 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 862920 T5728 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 862933 T5728 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 863517 T5728 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 863521 T5728 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 863523 T5728 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 863528 T5728 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 863562 T5728 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 863563 T5728 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394948259589/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394948247974/jetty3/
[junit4] 2> 863563 T5728 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@67041ec7
[junit4] 2> 863564 T5728 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394948247974/jetty3
[junit4] 2> 863565 T5728 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.
[...truncated too long message...]
bCmdsTest-jetty2-1394948255568/collection2_shard2_replica2/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394948255568/collection2_shard2_replica2/data/index;done=false>>]
[junit4] 2> 1011417 T5709 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394948255568/collection2_shard2_replica2/data/index
[junit4] 2> 1011417 T5709 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1011418 T5709 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> ASYNC NEW_CORE C3793 name=collection2_shard2_replica1 org.apache.solr.core.SolrCore@4c983f39 url=http://127.0.0.1:33953/collection2_shard2_replica1 node=127.0.0.1:33953_ C3793_STATE=coll:collection2 core:collection2_shard2_replica1 props:{state=active, base_url=http://127.0.0.1:33953, core=collection2_shard2_replica1, node_name=127.0.0.1:33953_}
[junit4] 2> 1011428 T5764 C3793 P33953 oasc.SyncStrategy.sync WARN Closed, skipping sync up.
[junit4] 2> 1011428 T5764 oasc.ShardLeaderElectionContext.rejoinLeaderElection Not rejoining election because CoreContainer is shutdown
[junit4] 2> 1011428 T5764 oasc.SolrCore.close [collection2_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@4c983f39
[junit4] 2> 1011439 T5764 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=21029,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=3215838,transaction_logs_total_number=1}
[junit4] 2> 1011439 T5764 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 1011439 T5764 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1011439 T5764 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 1011440 T5764 oasc.SolrCore.closeSearcher [collection2_shard2_replica1] Closing main searcher on request.
[junit4] 2> 1011441 T5764 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1011441 T5764 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty5-1394948267607/collection2_shard2_replica1/data [CachedDir<<refCount=0;path=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty5-1394948267607/collection2_shard2_replica1/data;done=false>>]
[junit4] 2> 1011441 T5764 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty5-1394948267607/collection2_shard2_replica1/data
[junit4] 2> 1011441 T5764 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty5-1394948267607/collection2_shard2_replica1/data/index [CachedDir<<refCount=0;path=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty5-1394948267607/collection2_shard2_replica1/data/index;done=false>>]
[junit4] 2> 1011442 T5764 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty5-1394948267607/collection2_shard2_replica1/data/index
[junit4] 2> 1011442 T5764 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1011442 T5764 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1011442 T5764 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1011442 T5764 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> NOTE: test params are: codec=Appending, sim=DefaultSimilarity, locale=no, timezone=PRT
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=130026056,total=477233152
[junit4] 2> NOTE: All tests run in this JVM: [TestRandomMergePolicy, ConnectionManagerTest, SpellCheckCollatorTest, TestComponentsName, PingRequestHandlerTest, DocValuesMissingTest, SimplePostToolTest, DocumentAnalysisRequestHandlerTest, ChaosMonkeyNothingIsSafeTest, CurrencyFieldOpenExchangeTest, TestImplicitCoreProperties, DirectSolrSpellCheckerTest, DeleteInactiveReplicaTest, StandardRequestHandlerTest, DisMaxRequestHandlerTest, TestHashPartitioner, TestFieldTypeCollectionResource, TestCoreDiscovery, HdfsUnloadDistributedZkTest, HighlighterTest, PrimUtilsTest, TestNumberUtils, MultiTermTest, DistributedQueryComponentOptimizationTest, TestQuerySenderListener, SolrCoreCheckLockOnStartupTest, TestMultiCoreConfBootstrap, SolrRequestParserTest, TestFuzzyAnalyzedSuggestions, IndexBasedSpellCheckerTest, CursorPagingTest, ShardRoutingCustomTest, TestXIncludeConfig, DirectUpdateHandlerTest, TestAnalyzedSuggestions, FullSolrCloudDistribCmdsTest]
[junit4] Completed on J1 in 163.65s, 1 test, 1 error <<< FAILURES!
[...truncated 826 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:474: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:447: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:45: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/common-build.xml:490: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:1276: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:908: There were test failures: 369 suites, 1582 tests, 1 error, 35 ignored (7 assumptions)
Total time: 145 minutes 11 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure