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 2013/12/24 05:09:22 UTC
[JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4543 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4543/
1 tests failed.
REGRESSION: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
Error Message:
Stack Trace:
java.lang.AssertionError
at __randomizedtesting.SeedInfo.seed([25E9FCD590DE1A12:A40F72CDE7817A2E]:0)
at org.junit.Assert.fail(Assert.java:92)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertFalse(Assert.java:68)
at org.junit.Assert.assertFalse(Assert.java:79)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.deleteCollectionWithDownNodes(CollectionsAPIDistributedZkTest.java:390)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:203)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:849)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 10290 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> 332909 T816 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 332914 T816 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./solrtest-CollectionsAPIDistributedZkTest-1387856069893
[junit4] 2> 332915 T816 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 332916 T817 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 333017 T816 oasc.ZkTestServer.run start zk server on port:40838
[junit4] 2> 333018 T816 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 333021 T823 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1945ff9c name:ZooKeeperConnection Watcher:127.0.0.1:40838 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 333021 T816 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 333022 T816 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 333034 T816 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 333036 T825 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@78fccfa1 name:ZooKeeperConnection Watcher:127.0.0.1:40838/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 333036 T816 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 333036 T816 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 333040 T816 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 333043 T816 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 333056 T816 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 333059 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 333060 T816 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 333065 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 333066 T816 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 333169 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 333170 T816 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 333173 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 333173 T816 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 333188 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 333189 T816 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 333193 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 333193 T816 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 333208 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 333208 T816 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 333212 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 333212 T816 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 333225 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 333225 T816 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 333239 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 333240 T816 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 333243 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 333243 T816 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> Using old style solr.xml
[junit4] 2> 333255 T816 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 333265 T827 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@33a91cbe name:ZooKeeperConnection Watcher:127.0.0.1:40838 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 333265 T816 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 333265 T816 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 333269 T816 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 333276 T829 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50fb2d29 name:ZooKeeperConnection Watcher:127.0.0.1:40838/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 333277 T816 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 333279 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf2/solrconfig.xml
[junit4] 2> 333279 T816 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.xml
[junit4] 2> 333284 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf2/schema.xml
[junit4] 2> 333284 T816 oascc.SolrZkClient.makePath makePath: /configs/conf2/schema.xml
[junit4] 2> 333388 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf2/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 333389 T816 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 333392 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf2/stopwords.txt
[junit4] 2> 333392 T816 oascc.SolrZkClient.makePath makePath: /configs/conf2/stopwords.txt
[junit4] 2> 333411 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf2/protwords.txt
[junit4] 2> 333412 T816 oascc.SolrZkClient.makePath makePath: /configs/conf2/protwords.txt
[junit4] 2> 333414 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf2/currency.xml
[junit4] 2> 333415 T816 oascc.SolrZkClient.makePath makePath: /configs/conf2/currency.xml
[junit4] 2> 333418 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf2/open-exchange-rates.json
[junit4] 2> 333418 T816 oascc.SolrZkClient.makePath makePath: /configs/conf2/open-exchange-rates.json
[junit4] 2> 333429 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf2/mapping-ISOLatin1Accent.txt
[junit4] 2> 333430 T816 oascc.SolrZkClient.makePath makePath: /configs/conf2/mapping-ISOLatin1Accent.txt
[junit4] 2> 333436 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf2/old_synonyms.txt
[junit4] 2> 333436 T816 oascc.SolrZkClient.makePath makePath: /configs/conf2/old_synonyms.txt
[junit4] 2> 333439 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf2/synonyms.txt
[junit4] 2> 333440 T816 oascc.SolrZkClient.makePath makePath: /configs/conf2/synonyms.txt
[junit4] 2> 333443 T816 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/elevate.xml to /configs/conf2/elevate.xml
[junit4] 2> 333444 T816 oascc.SolrZkClient.makePath makePath: /configs/conf2/elevate.xml
[junit4] 2> 333770 T816 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 333775 T816 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:40845
[junit4] 2> 333776 T816 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 333776 T816 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 333777 T816 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1387856070426
[junit4] 2> 333777 T816 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1387856070426/'
[junit4] 2> 333818 T816 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1387856070426/solr.xml
[junit4] 2> 333921 T816 oasc.CoreContainer.<init> New CoreContainer 1618565623
[junit4] 2> 333922 T816 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1387856070426/]
[junit4] 2> 333924 T816 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 333925 T816 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 333925 T816 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 333925 T816 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 333926 T816 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 333926 T816 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 333927 T816 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 333927 T816 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 333928 T816 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 333948 T816 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 333949 T816 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 333949 T816 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 333950 T816 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40838/solr
[junit4] 2> 333950 T816 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 333951 T816 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 333953 T840 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@449c30fd name:ZooKeeperConnection Watcher:127.0.0.1:40838 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 333954 T816 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 333957 T816 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 333967 T842 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@47c8d05a name:ZooKeeperConnection Watcher:127.0.0.1:40838/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 333968 T816 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 333970 T816 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 333975 T816 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 333979 T816 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 333982 T816 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40845_
[junit4] 2> 333989 T816 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40845_
[junit4] 2> 333994 T816 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 334018 T816 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 334028 T816 oasc.Overseer.start Overseer (id=90954535396900869-127.0.0.1:40845_-n_0000000000) starting
[junit4] 2> 334041 T816 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 334045 T844 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 334046 T816 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 334048 T816 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 334050 T816 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 334053 T843 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 334056 T816 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4] 2> 334057 T816 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 334059 T816 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 334061 T847 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6bc8752a name:ZooKeeperConnection Watcher:127.0.0.1:40838/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 334061 T816 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 334063 T816 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 334065 T816 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 334271 T816 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 334273 T816 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:40852
[junit4] 2> 334274 T816 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 334275 T816 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 334275 T816 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1387856071043
[junit4] 2> 334275 T816 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1387856071043/'
[junit4] 2> 334302 T816 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1387856071043/solr.xml
[junit4] 2> 334368 T816 oasc.CoreContainer.<init> New CoreContainer 124451182
[junit4] 2> 334368 T816 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1387856071043/]
[junit4] 2> 334370 T816 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 334370 T816 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 334370 T816 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 334371 T816 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 334371 T816 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 334371 T816 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 334371 T816 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 334372 T816 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 334372 T816 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 334384 T816 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 334385 T816 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 334385 T816 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 334385 T816 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40838/solr
[junit4] 2> 334386 T816 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 334386 T816 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 334390 T858 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@36a201f4 name:ZooKeeperConnection Watcher:127.0.0.1:40838 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 334391 T816 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 334407 T816 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 334409 T860 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7784fc02 name:ZooKeeperConnection Watcher:127.0.0.1:40838/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 334410 T816 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 334423 T816 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 335428 T816 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40852_
[junit4] 2> 335430 T816 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40852_
[junit4] 2> 335434 T842 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 335435 T860 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 335435 T847 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 335454 T816 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4] 2> 335455 T816 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 335768 T816 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 335771 T816 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:40860
[junit4] 2> 335772 T816 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 335772 T816 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 335773 T816 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1387856072434
[junit4] 2> 335773 T816 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1387856072434/'
[junit4] 2> 335815 T816 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1387856072434/solr.xml
[junit4] 2> 335920 T816 oasc.CoreContainer.<init> New CoreContainer 1066672803
[junit4] 2> 335921 T816 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1387856072434/]
[junit4] 2> 335922 T816 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 335923 T816 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 335923 T816 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 335924 T816 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 335924 T816 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 335925 T816 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 335925 T816 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 335926 T816 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 335926 T816 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 335949 T816 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 335949 T816 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 335949 T816 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 335950 T816 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40838/solr
[junit4] 2> 335950 T816 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 335951 T816 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 335954 T872 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3d0e8008 name:ZooKeeperConnection Watcher:127.0.0.1:40838 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 335955 T816 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 335957 T816 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 335968 T874 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e92fbc8 name:ZooKeeperConnection Watcher:127.0.0.1:40838/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 335968 T816 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 335984 T816 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 336988 T816 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40860_
[junit4] 2> 336990 T816 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40860_
[junit4] 2> 336993 T874 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 336994 T847 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 336994 T860 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 336994 T842 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 337010 T816 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4] 2> 337010 T816 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 337273 T816 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 337275 T816 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:40865
[junit4] 2> 337276 T816 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 337277 T816 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 337277 T816 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990
[junit4] 2> 337278 T816 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990/'
[junit4] 2> 337322 T816 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990/solr.xml
[junit4] 2> 337435 T816 oasc.CoreContainer.<init> New CoreContainer 1223143131
[junit4] 2> 337436 T816 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990/]
[junit4] 2> 337438 T816 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 337438 T816 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 337439 T816 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 337439 T816 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 337439 T816 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 337440 T816 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 337440 T816 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 337441 T816 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 337441 T816 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 337463 T816 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 337463 T816 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 337464 T816 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 337464 T816 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40838/solr
[junit4] 2> 337465 T816 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 337466 T816 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 337469 T886 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e67be50 name:ZooKeeperConnection Watcher:127.0.0.1:40838 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 337469 T816 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 337515 T816 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 337518 T888 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4aebe4ba name:ZooKeeperConnection Watcher:127.0.0.1:40838/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 337518 T816 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 337531 T816 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 338536 T816 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40865_
[junit4] 2> 338538 T816 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40865_
[junit4] 2> 338542 T842 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 338543 T874 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 338543 T860 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 338542 T847 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 338542 T888 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 338557 T816 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4] 2> 338558 T816 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 338862 T816 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 338865 T816 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:40873
[junit4] 2> 338866 T816 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 338866 T816 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 338867 T816 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1387856075537
[junit4] 2> 338867 T816 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1387856075537/'
[junit4] 2> 338908 T816 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1387856075537/solr.xml
[junit4] 2> 339009 T816 oasc.CoreContainer.<init> New CoreContainer 1777136839
[junit4] 2> 339010 T816 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1387856075537/]
[junit4] 2> 339012 T816 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 339012 T816 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 339013 T816 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 339013 T816 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 339014 T816 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 339014 T816 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 339014 T816 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 339015 T816 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 339015 T816 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 339035 T816 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 339036 T816 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 339037 T816 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 339037 T816 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40838/solr
[junit4] 2> 339038 T816 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 339039 T816 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 339045 T900 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bd494aa name:ZooKeeperConnection Watcher:127.0.0.1:40838 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 339046 T816 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 339058 T816 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 339061 T902 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@27978891 name:ZooKeeperConnection Watcher:127.0.0.1:40838/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 339061 T816 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 339083 T816 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 340089 T816 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40873_
[junit4] 2> 340091 T816 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40873_
[junit4] 2> 340095 T860 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 340095 T847 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 340095 T888 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 340096 T902 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 340095 T842 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 340095 T874 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 340121 T816 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4] 2> 340122 T816 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 340203 T850 oasha.CollectionsHandler.handleCreateAction Creating Collection : replicationFactor=2&router.name=compositeId&numShards=2&collection.configName=conf1&wt=javabin&action=CREATE&version=2&name=solrj_collection&router.field=myOwnField
[junit4] 2> 340206 T842 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4] 2> 340208 T844 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
[junit4] 2> "operation":"createcollection",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"solrj_collection",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "router.name":"compositeId",
[junit4] 2> "router.field":"myOwnField"}
[junit4] 2> 340208 T844 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
[junit4] 2> "operation":"createcollection",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"solrj_collection",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "router.name":"compositeId",
[junit4] 2> "router.field":"myOwnField"}
[junit4] 2> 340209 T844 oasc.OverseerCollectionProcessor.createConfNode creating collections conf node /collections/solrj_collection
[junit4] 2> 340209 T844 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
[junit4] 2> 340230 T842 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 340232 T843 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 340233 T843 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
[junit4] 2> 340233 T843 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
[junit4] 2> 340242 T842 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 340259 T847 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 340259 T860 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 340259 T842 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 340259 T902 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 340259 T874 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 340259 T888 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 340331 T844 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
[junit4] 2> 340331 T844 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:40852_
[junit4] 2> 340332 T844 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:40873_
[junit4] 2> 340332 T844 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:40860_
[junit4] 2> 340333 T844 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:40865_
[junit4] 2> 340338 T878 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down
[junit4] 2> 340338 T892 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down
[junit4] 2> 340338 T864 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down
[junit4] 2> 340338 T851 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down
[junit4] 2> 340340 T842 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 340340 T878 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 340349 T892 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 340350 T851 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 340350 T864 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 340351 T843 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 340352 T843 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:40865",
[junit4] 2> "core":"solrj_collection_shard2_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:40865_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 340356 T842 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 340357 T843 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:40873",
[junit4] 2> "core":"solrj_collection_shard1_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:40873_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 340373 T842 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 340375 T843 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:40860",
[junit4] 2> "core":"solrj_collection_shard2_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:40860_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 340390 T842 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 340391 T843 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:40852",
[junit4] 2> "core":"solrj_collection_shard1_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:40852_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 340412 T842 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 340516 T860 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 340516 T902 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 340516 T847 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 340516 T874 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 340516 T888 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 340516 T842 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 341341 T878 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
[junit4] 2> 341342 T878 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990/solr.xml
[junit4] 2> 341343 T878 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990/solrj_collection_shard2_replica2
[junit4] 2> 341343 T878 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 341344 T878 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 341345 T878 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 341346 T878 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990/solrj_collection_shard2_replica2/'
[junit4] 2> 341351 T892 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
[junit4] 2> 341352 T864 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
[junit4] 2> 341351 T851 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
[junit4] 2> 341352 T892 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1387856075537/solr.xml
[junit4] 2> 341353 T864 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1387856072434/solr.xml
[junit4] 2> 341353 T892 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1387856075537/solrj_collection_shard1_replica2
[junit4] 2> 341353 T851 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1387856071043/solr.xml
[junit4] 2> 341353 T864 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1387856072434/solrj_collection_shard2_replica1
[junit4] 2> 341354 T851 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1387856071043/solrj_collection_shard1_replica1
[junit4] 2> 341354 T892 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 341355 T851 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 341355 T864 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 341356 T892 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 341356 T851 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 341357 T864 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 341356 T892 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 341357 T864 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 341357 T851 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 341359 T892 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1387856075537/solrj_collection_shard1_replica2/'
[junit4] 2> 341359 T864 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1387856072434/solrj_collection_shard2_replica1/'
[junit4] 2> 341359 T851 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1387856071043/solrj_collection_shard1_replica1/'
[junit4] 2> 341418 T878 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 341435 T892 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 341437 T851 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 341441 T864 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 341527 T878 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 341544 T892 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 341544 T851 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 341548 T864 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 341629 T878 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 341643 T878 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
[junit4] 2> 341646 T892 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 341646 T851 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 341649 T864 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 341659 T892 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
[junit4] 2> 341661 T851 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
[junit4] 2> 341662 T864 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
[junit4] 2> 343015 T851 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 343047 T851 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 343056 T851 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 343063 T878 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 343078 T878 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 343079 T864 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 343087 T878 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 343096 T864 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 343104 T864 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 343105 T851 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 343114 T851 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 343121 T878 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 343123 T851 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 343125 T851 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 343127 T851 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 343127 T851 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 343129 T878 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 343129 T851 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 343130 T851 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 343130 T851 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 343131 T851 oasc.SolrCore.<init> [solrj_collection_shard1_replica1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1387856071043/solrj_collection_shard1_replica1/, dataDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1387856071043/solrj_collection_shard1_replica1/data/
[junit4] 2> 343131 T864 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 343131 T851 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7ce3d64e
[junit4] 2> 343134 T851 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1387856071043/solrj_collection_shard1_replica1/data
[junit4] 2> 343134 T851 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1387856071043/solrj_collection_shard1_replica1/data/index/
[junit4] 2> 343135 T851 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica1] Solr index directory '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1387856071043/solrj_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4] 2> 343135 T878 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 343136 T851 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1387856071043/solrj_collection_shard1_replica1/data/index
[junit4] 2> 343137 T851 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=807361492, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 343137 T878 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 343138 T878 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 343138 T851 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@768a1787 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@def5095),segFN=segments_1,generation=1}
[junit4] 2> 343138 T878 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 343139 T851 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 343139 T864 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 343141 T878 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 343141 T878 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 343142 T878 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 343142 T878 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990/solrj_collection_shard2_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990/solrj_collection_shard2_replica2/data/
[junit4] 2> 343143 T878 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7ce3d64e
[junit4] 2> 343145 T878 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990/solrj_collection_shard2_replica2/data
[junit4] 2> 343145 T878 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990/solrj_collection_shard2_replica2/data/index/
[junit4] 2> 343146 T878 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4] 2> 343146 T878 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990/solrj_collection_shard2_replica2/data/index
[junit4] 2> 343147 T851 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 343147 T864 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 343147 T878 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=807361492, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 343148 T851 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 343149 T851 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 343150 T878 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@5db7e8d2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@763fdc1c),segFN=segments_1,generation=1}
[junit4] 2> 343150 T864 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 343150 T878 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 343150 T851 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 343151 T864 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 343152 T851 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 343152 T864 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 343153 T851 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 343154 T851 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 343154 T851 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 343155 T851 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 343155 T864 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 343156 T864 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 343156 T851 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 343157 T864 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 343157 T892 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 343157 T864 oasc.SolrCore.<init> [solrj_collection_shard2_replica1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1387856072434/solrj_collection_shard2_replica1/, dataDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1387856072434/solrj_collection_shard2_replica1/data/
[junit4] 2> 343157 T851 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 343158 T878 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 343158 T864 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7ce3d64e
[junit4] 2> 343159 T878 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 343159 T851 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 343160 T878 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 343160 T864 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1387856072434/solrj_collection_shard2_replica1/data
[junit4] 2> 343160 T878 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 343160 T851 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 343161 T878 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 343161 T864 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1387856072434/solrj_collection_shard2_replica1/data/index/
[junit4] 2> 343163 T851 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 343162 T878 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 343163 T851 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 343163 T864 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica1] Solr index directory '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1387856072434/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4] 2> 343164 T851 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 343164 T878 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 343165 T864 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1387856072434/solrj_collection_shard2_replica1/data/index
[junit4] 2> 343165 T878 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 343165 T851 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 343166 T864 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=807361492, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 343166 T878 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 343168 T864 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@590f1252 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@39feb90f),segFN=segments_1,generation=1}
[junit4] 2> 343168 T878 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 343168 T864 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 343169 T878 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 343169 T892 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 343169 T878 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 343170 T878 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 343171 T878 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 343172 T878 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 343173 T878 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 343174 T878 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 343175 T892 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 343176 T864 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 343177 T864 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 343177 T864 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 343178 T864 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 343178 T864 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 343179 T864 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 343180 T864 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 343181 T864 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 343181 T864 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 343182 T864 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 343183 T864 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 343184 T864 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 343185 T864 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 343186 T864 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 343187 T864 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 343188 T864 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 343189 T864 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 343192 T851 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 343192 T878 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 343193 T864 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 343200 T892 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 343203 T878 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 343203 T878 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 343204 T851 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 343204 T851 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 343204 T878 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=16, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=96.609375, floorSegmentMB=2.1435546875, forceMergeDeletesPctAllowed=18.5704475727798, segmentsPerTier=23.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5444671152427695
[junit4] 2> 343205 T864 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 343206 T878 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@5db7e8d2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@763fdc1c),segFN=segments_1,generation=1}
[junit4] 2> 343206 T864 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 343206 T851 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=16, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=96.609375, floorSegmentMB=2.1435546875, forceMergeDeletesPctAllowed=18.5704475727798, segmentsPerTier=23.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5444671152427695
[junit4] 2> 343207 T892 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 343208 T851 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@768a1787 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@def5095),segFN=segments_1,generation=1}
[junit4] 2> 343206 T878 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 343208 T851 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 343207 T864 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=16, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=96.609375, floorSegmentMB=2.1435546875, forceMergeDeletesPctAllowed=18.5704475727798, segmentsPerTier=23.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5444671152427695
[junit4] 2> 343209 T851 oass.SolrIndexSearcher.<init> Opening Searcher@2be8db3d main
[junit4] 2> 343209 T878 oass.SolrIndexSearcher.<init> Opening Searcher@578a74ad main
[junit4] 2> 343210 T864 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@590f1252 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@39feb90f),segFN=segments_1,generation=1}
[junit4] 2> 343211 T864 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 343212 T864 oass.SolrIndexSearcher.<init> Opening Searcher@52a1c92 main
[junit4] 2> 343213 T892 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 343215 T908 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica1] Registered new searcher Searcher@2be8db3d main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 343216 T909 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica2] Registered new searcher Searcher@578a74ad main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 343216 T892 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 343217 T892 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 343217 T892 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 343218 T910 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica1] Registered new searcher Searcher@52a1c92 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 343220 T892 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 343220 T892 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 343221 T892 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 343222 T892 oasc.SolrCore.<init> [solrj_collection_shard1_replica2] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1387856075537/solrj_collection_shard1_replica2/, dataDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1387856075537/solrj_collection_shard1_replica2/data/
[junit4] 2> 343222 T878 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica2
[junit4] 2> 343222 T851 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica1
[junit4] 2> 343223 T878 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica2 address:http://127.0.0.1:40865 collection:solrj_collection shard:shard2
[junit4] 2> 343222 T892 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7ce3d64e
[junit4] 2> 343223 T851 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica1 address:http://127.0.0.1:40852 collection:solrj_collection shard:shard1
[junit4] 2> 343224 T864 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica1
[junit4] 2> 343224 T878 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard2/election
[junit4] 2> 343225 T851 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard1/election
[junit4] 2> 343225 T864 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica1 address:http://127.0.0.1:40860 collection:solrj_collection shard:shard2
[junit4] 2> 343225 T892 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1387856075537/solrj_collection_shard1_replica2/data
[junit4] 2> 343227 T892 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1387856075537/solrj_collection_shard1_replica2/data/index/
[junit4] 2> 343227 T864 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard2/election
[junit4] 2> 343227 T892 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica2] Solr index directory '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1387856075537/solrj_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4] 2> 343229 T892 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1387856075537/solrj_collection_shard1_replica2/data/index
[junit4] 2> 343229 T892 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=807361492, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 343230 T892 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@66ff90bd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@28cf253a),segFN=segments_1,generation=1}
[junit4] 2> 343231 T892 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 343237 T892 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 343238 T892 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 343238 T892 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 343239 T892 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 343239 T892 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 343240 T892 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 343240 T892 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 343241 T892 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 343241 T892 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 343242 T892 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 343243 T892 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[juni
[...truncated too long message...]
lbacks=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,transaction_logs_total_size=0,transaction_logs_total_number=0}
[junit4] 2> 511011 T1123 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 511011 T1123 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 511012 T1123 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 511012 T1123 oasc.SolrCore.closeSearcher [awholynewcollection_0_shard3_replica2] Closing main searcher on request.
[junit4] 2> 511012 T1123 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 511013 T1123 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990/awholynewcollection_0_shard3_replica2/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990/awholynewcollection_0_shard3_replica2/data;done=false>>]
[junit4] 2> 511013 T1123 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990/awholynewcollection_0_shard3_replica2/data
[junit4] 2> 511013 T1123 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990/awholynewcollection_0_shard3_replica2/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990/awholynewcollection_0_shard3_replica2/data/index;done=false>>]
[junit4] 2> 511014 T1123 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1387856073990/awholynewcollection_0_shard3_replica2/data/index
[junit4] 2> 511014 T1123 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0/leaders/shard3
[junit4] 2> 511014 T1123 oasc.SolrException.log ERROR There was a problem trying to register as the leader:org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections
[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.exists(ZooKeeper.java:1041)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:201)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:198)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:198)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:409)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:378)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:365)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:102)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:263)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
[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:138)
[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> 511015 T1123 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/awholynewcollection_0/leader_elect/shard3/election/90954535396900883-core_node4-n_0000000004
[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.delete(ZooKeeper.java:873)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:169)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:166)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:166)
[junit4] 2> at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:66)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:266)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
[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:138)
[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> 511016 T1123 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 511016 T1123 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/awholynewcollection_0/leader_elect/shard5/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:252)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[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:138)
[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=Lucene40, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=sr_ME, timezone=Etc/Zulu
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=6,free=328859312,total=510656512
[junit4] 2> NOTE: All tests run in this JVM: [TestComponentsName, FileUtilsTest, SolrIndexConfigTest, OpenCloseCoreStressTest, TestRangeQuery, TestCSVResponseWriter, OpenExchangeRatesOrgProviderTest, TestSimpleQParserPlugin, TestFieldResource, TestBinaryField, TestStressUserVersions, TestImplicitCoreProperties, TestIBSimilarityFactory, TestCodecSupport, TestClassNameShortening, SolrPluginUtilsTest, NoCacheHeaderTest, TimeZoneUtilsTest, HdfsDirectoryTest, TestCollationField, TestReload, BlockCacheTest, DocumentAnalysisRequestHandlerTest, TestMultiCoreConfBootstrap, DirectUpdateHandlerTest, BasicDistributedZk2Test, TestQuerySenderListener, SignatureUpdateProcessorFactoryTest, TestMaxScoreQueryParser, JSONWriterTest, TestLazyCores, TestDFRSimilarityFactory, AddSchemaFieldsUpdateProcessorFactoryTest, CollectionsAPIDistributedZkTest]
[junit4] Completed on J1 in 178.36s, 1 test, 1 failure <<< FAILURES!
[...truncated 777 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:453: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:433: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:491: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1304: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:937: There were test failures: 357 suites, 1572 tests, 1 failure, 34 ignored (6 assumptions)
Total time: 70 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-Tests-trunk-Java7 - Build # 4544 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4544/
1 tests failed.
REGRESSION: org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch
Error Message:
No live SolrServers available to handle this request:[http://127.0.0.1:37576/ik_bxr/p/collection1, http://127.0.0.1:37583/ik_bxr/p/collection1]
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:37576/ik_bxr/p/collection1, http://127.0.0.1:37583/ik_bxr/p/collection1]
at __randomizedtesting.SeedInfo.seed([1F96BB45067FC674:9E70355D7120A648]:0)
at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:352)
at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:640)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:90)
at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.queryServer(AbstractFullDistribZkTestBase.java:1325)
at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:542)
at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:521)
at org.apache.solr.cloud.BasicDistributedZk2Test.brindDownShardIndexSomeDocsAndRecover(BasicDistributedZk2Test.java:305)
at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:117)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:849)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Caused by: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: no servers hosting shard:
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:495)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:283)
... 49 more
Build Log:
[...truncated 10394 lines...]
[junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4] 2> 814210 T2480 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /ik_bxr/p
[junit4] 2> 814216 T2480 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1387882246582
[junit4] 2> 814218 T2480 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 814219 T2481 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 814320 T2480 oasc.ZkTestServer.run start zk server on port:37566
[junit4] 2> 814321 T2480 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 814325 T2487 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6425a259 name:ZooKeeperConnection Watcher:127.0.0.1:37566 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 814325 T2480 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 814325 T2480 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 814337 T2480 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 814339 T2489 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1dce6f name:ZooKeeperConnection Watcher:127.0.0.1:37566/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 814339 T2480 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 814339 T2480 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 814349 T2480 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 814351 T2480 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 814357 T2480 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 814360 T2480 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 814360 T2480 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 814373 T2480 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 814373 T2480 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 814477 T2480 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 814477 T2480 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 814480 T2480 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 814481 T2480 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 814483 T2480 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 814484 T2480 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 814486 T2480 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 814487 T2480 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 814496 T2480 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 814496 T2480 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 814499 T2480 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 814499 T2480 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 814502 T2480 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 814502 T2480 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 814505 T2480 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 814505 T2480 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 814513 T2480 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 814513 T2480 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 814739 T2480 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 814743 T2480 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:37569
[junit4] 2> 814743 T2480 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 814743 T2480 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 814744 T2480 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1387882246881
[junit4] 2> 814744 T2480 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1387882246881/'
[junit4] 2> 814773 T2480 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1387882246881/solr.xml
[junit4] 2> 814848 T2480 oasc.CoreContainer.<init> New CoreContainer 2072324502
[junit4] 2> 814849 T2480 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1387882246881/]
[junit4] 2> 814851 T2480 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 814851 T2480 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 814851 T2480 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 814851 T2480 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 814852 T2480 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 814852 T2480 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 814852 T2480 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 814853 T2480 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 814853 T2480 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 814866 T2480 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 814867 T2480 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 814867 T2480 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 814867 T2480 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:37566/solr
[junit4] 2> 814868 T2480 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 814868 T2480 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 814871 T2500 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@79de1053 name:ZooKeeperConnection Watcher:127.0.0.1:37566 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 814872 T2480 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 814884 T2480 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 814885 T2502 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e697efb name:ZooKeeperConnection Watcher:127.0.0.1:37566/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 814886 T2480 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 814888 T2480 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 814898 T2480 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 814901 T2480 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 814910 T2480 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37569_ik_bxr%2Fp
[junit4] 2> 814911 T2480 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37569_ik_bxr%2Fp
[junit4] 2> 814913 T2480 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 814933 T2480 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 814935 T2480 oasc.Overseer.start Overseer (id=90956250912587779-127.0.0.1:37569_ik_bxr%2Fp-n_0000000000) starting
[junit4] 2> 814947 T2480 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 814959 T2504 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 814959 T2480 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 814962 T2480 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 814964 T2480 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 814965 T2503 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 814970 T2505 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 814970 T2505 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 814971 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 814971 T2505 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 814972 T2503 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 814973 T2503 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:37569/ik_bxr/p",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37569_ik_bxr%2Fp",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 814973 T2503 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 814973 T2503 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 814982 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 814983 T2502 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> 815973 T2505 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 815973 T2505 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1387882246881/collection1
[junit4] 2> 815974 T2505 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 815974 T2505 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 815975 T2505 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 815976 T2505 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1387882246881/collection1/'
[junit4] 2> 815978 T2505 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1387882246881/collection1/lib/README' to classloader
[junit4] 2> 815979 T2505 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1387882246881/collection1/lib/classes/' to classloader
[junit4] 2> 816049 T2505 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 816156 T2505 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 816258 T2505 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 816270 T2505 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 816795 T2505 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 816804 T2505 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 816807 T2505 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 816819 T2505 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 816823 T2505 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 816827 T2505 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 816828 T2505 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 816828 T2505 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 816828 T2505 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 816829 T2505 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 816829 T2505 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 816829 T2505 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 816830 T2505 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1387882246881/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1387882246582/control/data/
[junit4] 2> 816830 T2505 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b7b0a83
[junit4] 2> 816831 T2505 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1387882246582/control/data
[junit4] 2> 816831 T2505 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1387882246582/control/data/index/
[junit4] 2> 816831 T2505 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1387882246582/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 816831 T2505 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1387882246582/control/data/index
[junit4] 2> 816832 T2505 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=25, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1266530420782062]
[junit4] 2> 816833 T2505 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@6d8937c7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5ccf139c),segFN=segments_1,generation=1}
[junit4] 2> 816833 T2505 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 816836 T2505 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 816836 T2505 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 816837 T2505 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 816837 T2505 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 816837 T2505 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 816837 T2505 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 816838 T2505 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 816838 T2505 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 816838 T2505 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 816839 T2505 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 816839 T2505 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 816839 T2505 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 816840 T2505 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 816840 T2505 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 816841 T2505 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 816841 T2505 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 816841 T2505 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 816853 T2505 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 816858 T2505 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 816858 T2505 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 816859 T2505 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=33, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 816860 T2505 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@6d8937c7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5ccf139c),segFN=segments_1,generation=1}
[junit4] 2> 816860 T2505 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 816860 T2505 oass.SolrIndexSearcher.<init> Opening Searcher@4746074e main
[junit4] 2> 816863 T2506 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4746074e main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 816865 T2505 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 816866 T2480 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4] 2> 816867 T2480 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 816866 T2509 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:37569/ik_bxr/p collection:control_collection shard:shard1
[junit4] 2> 816868 T2509 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 816869 T2480 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 816897 T2511 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3934b564 name:ZooKeeperConnection Watcher:127.0.0.1:37566/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 816897 T2480 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 816933 T2480 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 817000 T2509 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 817000 T2480 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 817002 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 817002 T2509 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 817003 T2509 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1770 name=collection1 org.apache.solr.core.SolrCore@31ba6811 url=http://127.0.0.1:37569/ik_bxr/p/collection1 node=127.0.0.1:37569_ik_bxr%2Fp C1770_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:37569/ik_bxr/p, core=collection1, node_name=127.0.0.1:37569_ik_bxr%2Fp}
[junit4] 2> 817003 T2509 C1770 P37569 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:37569/ik_bxr/p/collection1/
[junit4] 2> 817003 T2503 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 817003 T2509 C1770 P37569 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 817004 T2509 C1770 P37569 oasc.SyncStrategy.syncToMe http://127.0.0.1:37569/ik_bxr/p/collection1/ has no replicas
[junit4] 2> 817004 T2509 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:37569/ik_bxr/p/collection1/ shard1
[junit4] 2> 817004 T2509 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 817047 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 817069 T2502 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> 817069 T2511 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> 817085 T2503 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 817093 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 817199 T2502 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> 817199 T2511 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> 817238 T2509 oasc.ZkController.register We are http://127.0.0.1:37569/ik_bxr/p/collection1/ and leader is http://127.0.0.1:37569/ik_bxr/p/collection1/
[junit4] 2> 817238 T2509 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:37569/ik_bxr/p
[junit4] 2> 817238 T2509 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 817238 T2509 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 817239 T2509 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 817240 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 817240 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 817240 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 817240 T2509 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 817242 T2503 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 817242 T2503 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:37569/ik_bxr/p",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37569_ik_bxr%2Fp",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 817250 T2480 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 817251 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 817253 T2480 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:37573
[junit4] 2> 817254 T2480 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 817254 T2480 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 817255 T2480 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1387882249366
[junit4] 2> 817255 T2480 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1387882249366/'
[junit4] 2> 817297 T2480 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1387882249366/solr.xml
[junit4] 2> 817356 T2502 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> 817356 T2511 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> 817421 T2480 oasc.CoreContainer.<init> New CoreContainer 1782452535
[junit4] 2> 817422 T2480 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1387882249366/]
[junit4] 2> 817424 T2480 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 817424 T2480 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 817425 T2480 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 817425 T2480 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 817425 T2480 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 817426 T2480 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 817426 T2480 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 817427 T2480 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 817427 T2480 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 817447 T2480 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 817447 T2480 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 817448 T2480 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 817448 T2480 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:37566/solr
[junit4] 2> 817449 T2480 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 817450 T2480 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 817452 T2522 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71f44c26 name:ZooKeeperConnection Watcher:127.0.0.1:37566 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 817453 T2480 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 817456 T2480 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 817466 T2524 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@333b698d name:ZooKeeperConnection Watcher:127.0.0.1:37566/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 817466 T2480 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 817470 T2480 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 818473 T2480 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37573_ik_bxr%2Fp
[junit4] 2> 818500 T2480 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37573_ik_bxr%2Fp
[junit4] 2> 818504 T2502 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 818504 T2524 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 818504 T2511 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 818518 T2525 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 818518 T2525 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 818519 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 818519 T2525 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 818520 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 818520 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 818522 T2503 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 818522 T2503 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:37573/ik_bxr/p",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37573_ik_bxr%2Fp",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 818523 T2503 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 818523 T2503 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 818526 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 818629 T2524 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> 818629 T2511 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> 818629 T2502 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> 819521 T2525 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 819521 T2525 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1387882249366/collection1
[junit4] 2> 819521 T2525 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 819522 T2525 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 819523 T2525 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 819524 T2525 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1387882249366/collection1/'
[junit4] 2> 819526 T2525 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1387882249366/collection1/lib/classes/' to classloader
[junit4] 2> 819527 T2525 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1387882249366/collection1/lib/README' to classloader
[junit4] 2> 819598 T2525 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 819673 T2525 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 819774 T2525 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 819786 T2525 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 820441 T2525 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 820454 T2525 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 820459 T2525 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 820473 T2525 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 820479 T2525 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 820483 T2525 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 820484 T2525 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 820485 T2525 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 820486 T2525 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 820487 T2525 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 820487 T2525 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 820487 T2525 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 820488 T2525 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1387882249366/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1387882246582/jetty1/
[junit4] 2> 820488 T2525 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b7b0a83
[junit4] 2> 820489 T2525 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1387882246582/jetty1
[junit4] 2> 820489 T2525 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1387882246582/jetty1/index/
[junit4] 2> 820490 T2525 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1387882246582/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 820490 T2525 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1387882246582/jetty1/index
[junit4] 2> 820491 T2525 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=25, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1266530420782062]
[junit4] 2> 820492 T2525 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@6678d52f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5daef3db),segFN=segments_1,generation=1}
[junit4] 2> 820492 T2525 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 820497 T2525 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 820498 T2525 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 820498 T2525 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 820499 T2525 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 820499 T2525 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 820499 T2525 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 820500 T2525 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 820500 T2525 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 820501 T2525 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 820501 T2525 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 820502 T2525 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 820502 T2525 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 820503 T2525 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 820503 T2525 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 820504 T2525 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 820505 T2525 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 820505 T2525 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 820525 T2525 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 820531 T2525 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 820531 T2525 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 820532 T2525 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=33, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 820533 T2525 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@6678d52f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5daef3db),segFN=segments_1,generation=1}
[junit4] 2> 820533 T2525 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 820534 T2525 oass.SolrIndexSearcher.<init> Opening Searcher@42ae89db main
[junit4] 2> 820540 T2526 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@42ae89db main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 820546 T2525 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 820547 T2480 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4] 2> 820548 T2480 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 820547 T2529 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:37573/ik_bxr/p collection:collection1 shard:shard1
[junit4] 2> 820549 T2529 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 820578 T2529 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 820581 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 820581 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 820582 T2529 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 820582 T2529 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 820582 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> ASYNC NEW_CORE C1771 name=collection1 org.apache.solr.core.SolrCore@762f0331 url=http://127.0.0.1:37573/ik_bxr/p/collection1 node=127.0.0.1:37573_ik_bxr%2Fp C1771_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:37573/ik_bxr/p, core=collection1, node_name=127.0.0.1:37573_ik_bxr%2Fp}
[junit4] 2> 820582 T2529 C1771 P37573 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:37573/ik_bxr/p/collection1/
[junit4] 2> 820583 T2529 C1771 P37573 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 820583 T2529 C1771 P37573 oasc.SyncStrategy.syncToMe http://127.0.0.1:37573/ik_bxr/p/collection1/ has no replicas
[junit4] 2> 820583 T2529 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:37573/ik_bxr/p/collection1/ shard1
[junit4] 2> 820584 T2503 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 820584 T2529 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 820595 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 820602 T2502 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> 820602 T2524 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> 820602 T2511 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> 820616 T2503 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 820625 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 820727 T2502 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> 820728 T2511 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> 820727 T2524 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> 820767 T2529 oasc.ZkController.register We are http://127.0.0.1:37573/ik_bxr/p/collection1/ and leader is http://127.0.0.1:37573/ik_bxr/p/collection1/
[junit4] 2> 820767 T2529 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:37573/ik_bxr/p
[junit4] 2> 820767 T2529 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 820767 T2529 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 820768 T2529 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 820770 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 820770 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 820770 T2529 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 820770 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 820771 T2503 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 820772 T2503 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:37573/ik_bxr/p",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37573_ik_bxr%2Fp",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 820794 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 820897 T2502 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> 820897 T2524 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> 820897 T2511 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> 820908 T2480 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 820911 T2480 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:37576
[junit4] 2> 820911 T2480 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 820912 T2480 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 820912 T2480 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1387882252914
[junit4] 2> 820913 T2480 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1387882252914/'
[junit4] 2> 820956 T2480 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1387882252914/solr.xml
[junit4] 2> 821065 T2480 oasc.CoreContainer.<init> New CoreContainer 95694773
[junit4] 2> 821066 T2480 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1387882252914/]
[junit4] 2> 821068 T2480 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 821069 T2480 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 821069 T2480 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 821070 T2480 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 821070 T2480 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 821071 T2480 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 821071 T2480 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 821071 T2480 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 821072 T2480 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 821092 T2480 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 821092 T2480 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 821093 T2480 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 821093 T2480 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:37566/solr
[junit4] 2> 821094 T2480 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 821095 T2480 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 821097 T2540 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6c498d69 name:ZooKeeperConnection Watcher:127.0.0.1:37566 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 821098 T2480 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 821101 T2480 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 821108 T2542 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@612f9436 name:ZooKeeperConnection Watcher:127.0.0.1:37566/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 821109 T2480 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 821113 T2480 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 822118 T2480 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37576_ik_bxr%2Fp
[junit4] 2> 822120 T2480 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37576_ik_bxr%2Fp
[junit4] 2> 822124 T2502 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 822125 T2511 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 822125 T2542 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 822125 T2524 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 822139 T2543 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 822140 T2543 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 822141 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 822141 T2543 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 822142 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 822142 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 822144 T2503 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 822144 T2503 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:37576/ik_bxr/p",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37576_ik_bxr%2Fp",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 822145 T2503 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 822145 T2503 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 822154 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 822256 T2542 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> 822256 T2524 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> 822256 T2511 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> 822256 T2502 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> 823143 T2543 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 823143 T2543 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1387882252914/collection1
[junit4] 2> 823144 T2543 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 823144 T2543 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 823145 T2543 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 823146 T2543 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1387882252914/collection1/'
[junit4] 2> 823148 T2543 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1387882252914/collection1/lib/classes/' to classloader
[junit4] 2> 823149 T2543 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1387882252914/collection1/lib/README' to classloader
[junit4] 2> 823216 T2543 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 823283 T2543 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 823384 T2543 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 823393 T2543 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 824020 T2543 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 824042 T2543 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 824048 T2543 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 824067 T2543 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 824075 T2543 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 824083 T2543 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 824085 T2543 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 824085 T2543 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 824086 T2543 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 824087 T2543 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 824087 T2543 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 824088 T2543 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 824089 T2543 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1387882252914/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1387882246582/jetty2/
[junit4] 2> 824089 T2543 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b7b0a83
[junit4] 2> 824090 T2543 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1387882246582/jetty2
[junit4] 2> 824090 T2543 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1387882246582/jetty2/index/
[junit4] 2> 824091 T2543 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1387882246582/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 824091 T2543 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1387882246582/jetty2/index
[junit4] 2> 824092 T2543 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=25, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1266530420782062]
[junit4] 2> 824093 T2543 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@42d2cba0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@75c16f4),segFN=segments_1,generation=1}
[junit4] 2> 824093 T2543 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 824100 T2543 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 824101 T2543 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 824101 T2543 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 824102 T2543 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 824103 T2543 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 824103 T2543 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 824104 T2543 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 824104 T2543 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 824105 T2543 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 824105 T2543 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 824106 T2543 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 824106 T2543 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 824107 T2543 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 824108 T2543 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 824108 T2543 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 824109 T2543 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 824110 T2543 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 824137 T2543 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 824145 T2543 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 824146 T2543 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 824147 T2543 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=33, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 824148 T2543 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@42d2cba0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@75c16f4),segFN=segments_1,generation=1}
[junit4] 2> 824149 T2543 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 824149 T2543 oass.SolrIndexSearcher.<init> Opening Searcher@8990be0 main
[junit4] 2> 824155 T2544 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@8990be0 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 824159 T2543 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 824160 T2480 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4] 2> 824161 T2480 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 824160 T2547 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:37576/ik_bxr/p collection:collection1 shard:shard2
[junit4] 2> 824162 T2547 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 824185 T2547 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 824189 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 824189 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 824189 T2547 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 824190 T2547 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 824190 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> ASYNC NEW_CORE C1772 name=collection1 org.apache.solr.core.SolrCore@2e3fb5b3 url=http://127.0.0.1:37576/ik_bxr/p/collection1 node=127.0.0.1:37576_ik_bxr%2Fp C1772_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:37576/ik_bxr/p, core=collection1, node_name=127.0.0.1:37576_ik_bxr%2Fp}
[junit4] 2> 824190 T2547 C1772 P37576 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:37576/ik_bxr/p/collection1/
[junit4] 2> 824191 T2547 C1772 P37576 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 824191 T2503 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 824191 T2547 C1772 P37576 oasc.SyncStrategy.syncToMe http://127.0.0.1:37576/ik_bxr/p/collection1/ has no replicas
[junit4] 2> 824192 T2547 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:37576/ik_bxr/p/collection1/ shard2
[junit4] 2> 824192 T2547 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 824195 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 824197 T2511 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> 824197 T2524 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> 824197 T2502 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> 824197 T2542 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> 824202 T2503 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 824206 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 824310 T2511 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> 824310 T2542 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> 824310 T2524 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> 824310 T2502 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> 824353 T2547 oasc.ZkController.register We are http://127.0.0.1:37576/ik_bxr/p/collection1/ and leader is http://127.0.0.1:37576/ik_bxr/p/collection1/
[junit4] 2> 824353 T2547 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:37576/ik_bxr/p
[junit4] 2> 824353 T2547 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 824354 T2547 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 824354 T2547 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 824356 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 824356 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 824356 T2547 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 824356 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 824357 T2503 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 824358 T2503 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:37576/ik_bxr/p",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37576_ik_bxr%2Fp",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 824361 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 824408 T2480 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 824410 T2480 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:37579
[junit4] 2> 824411 T2480 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 824411 T2480 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 824412 T2480 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1387882256527
[junit4] 2> 824412 T2480 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1387882256527/'
[junit4] 2> 824441 T2480 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1387882256527/solr.xml
[junit4] 2> 824465 T2502 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> 824465 T2542 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> 824465 T2524 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> 824465 T2511 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> 824513 T2480 oasc.CoreContainer.<init> New CoreContainer 2035245562
[junit4] 2> 824514 T2480 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1387882256527/]
[junit4] 2> 824516 T2480 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 824516 T2480 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 824516 T2480 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 824517 T2480 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 824517 T2480 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 824517 T2480 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 824518 T2480 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 824518 T2480 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 824518 T2480 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 824531 T2480 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 824531 T2480 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 824532 T2480 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 824532 T2480 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:37566/solr
[junit4] 2> 824532 T2480 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 824533 T2480 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 824536 T2558 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@42d4c14f name:ZooKeeperConnection Watcher:127.0.0.1:37566 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 824537 T2480 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 824540 T2480 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 824542 T2560 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@292d0d8d name:ZooKeeperConnection Watcher:127.0.0.1:37566/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 824542 T2480 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 824558 T2480 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 825568 T2480 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37579_ik_bxr%2Fp
[junit4] 2> 825574 T2480 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37579_ik_bxr%2Fp
[junit4] 2> 825600 T2511 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 825603 T2542 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 825603 T2502 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 825603 T2524 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 825604 T2560 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 825651 T2561 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 825652 T2561 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 825655 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 825655 T2561 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 825655 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 825656 T2502 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 825657 T2503 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 825658 T2503 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:37579/ik_bxr/p",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37579_ik_bxr%2Fp",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 825658 T2503 oasc.Overseer$ClusterStateUp
[...truncated too long message...]
st-1387882246582/jetty3/index;done=false>>]
[junit4] 2> 890870 T2560 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1387882246582/jetty3/index
[junit4] 2> 890870 T2560 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue/qn-
[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.create(ZooKeeper.java:783)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:235)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:232)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:232)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.createData(DistributedQueue.java:284)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.offer(DistributedQueue.java:271)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:157)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:385)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:178)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:385)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:249)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
[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:138)
[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> 890871 T2560 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 890871 T2560 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 890872 T2560 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 890872 T2560 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:252)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[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:138)
[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> 890945 T2579 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene46: {foo_f=FSTOrd41, foo_d=PostingsFormat(name=Asserting), n_l1=PostingsFormat(name=FSTPulsing41), multiDefault=PostingsFormat(name=FSTPulsing41), _version_=PostingsFormat(name=Memory doPackFST= false), n_tl1=PostingsFormat(name=Memory doPackFST= false), n_tdt1=PostingsFormat(name=Memory doPackFST= false), a_t=PostingsFormat(name=FSTPulsing41), id=PostingsFormat(name=Asserting), SubjectTerms_mfacet=PostingsFormat(name=Memory doPackFST= false), range_facet_l=PostingsFormat(name=FSTPulsing41), a_si=PostingsFormat(name=Memory doPackFST= false), n_d1=PostingsFormat(name=FSTPulsing41), intDefault=PostingsFormat(name=Memory doPackFST= false), n_f1=PostingsFormat(name=Memory doPackFST= false), text=FSTOrd41, rnd_b=PostingsFormat(name=Asserting), range_facet_sl=PostingsFormat(name=Asserting), n_ti1=PostingsFormat(name=Asserting), foo_b=FSTOrd41, timestamp=PostingsFormat(name=FSTPulsing41), other_tl1=PostingsFormat(name=Memory doPackFST= false), n_tf1=PostingsFormat(name=FSTPulsing41), n_td1=PostingsFormat(name=Memory doPackFST= false), range_facet_si=PostingsFormat(name=FSTPulsing41), n_dt1=PostingsFormat(name=Memory doPackFST= false), oddField_s=PostingsFormat(name=Asserting)}, docValues:{timestamp=DocValuesFormat(name=Memory)}, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=fr, timezone=Asia/Qatar
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=271981392,total=504365056
[junit4] 2> NOTE: All tests run in this JVM: [AddSchemaFieldsUpdateProcessorFactoryTest, ZkNodePropsTest, DateFieldTest, SpellCheckCollatorTest, ShardRoutingCustomTest, TestCodecSupport, StatsComponentTest, TestXIncludeConfig, CurrencyFieldXmlFileTest, SpellingQueryConverterTest, TestSolrJ, DebugComponentTest, XsltUpdateRequestHandlerTest, TestRandomFaceting, DirectSolrSpellCheckerTest, TestMaxScoreQueryParser, TestNRTOpen, TestReload, TestAnalyzedSuggestions, TestFoldingMultitermQuery, CurrencyFieldOpenExchangeTest, TestCSVLoader, OpenCloseCoreStressTest, OutputWriterTest, ZkSolrClientTest, PrimUtilsTest, TestCSVResponseWriter, FieldFacetExtrasTest, NumericFieldsTest, BadIndexSchemaTest, DistributedQueryComponentCustomSortTest, BlockDirectoryTest, HdfsDirectoryTest, TestFastOutputStream, TestClassNameShortening, DocValuesMultiTest, TestRandomMergePolicy, TestRTGBase, TestStressUserVersions, StandardRequestHandlerTest, TimeZoneUtilsTest, TestFieldResource, UniqFieldsUpdateProcessorFactoryTest, TestRecovery, TestQueryTypes, TestSolrQueryParserResource, TestSolrDeletionPolicy2, TestStressLucene, FieldFacetTest, TestRangeQuery, BadCopyFieldTest, TestDFRSimilarityFactory, TestCollationField, TestComponentsName, HighlighterTest, DefaultValueUpdateProcessorTest, SolrIndexConfigTest, FileUtilsTest, JSONWriterTest, TestSchemaNameResource, TestIndexingPerformance, SuggesterWFSTTest, AbstractAnalyticsStatsTest, PreAnalyzedFieldTest, TestZkChroot, NoCacheHeaderTest, MinimalSchemaTest, SignatureUpdateProcessorFactoryTest, TestRecoveryHdfs, PingRequestHandlerTest, CoreContainerCoreInitFailuresTest, TestDefaultSimilarityFactory, TestOmitPositions, FullSolrCloudDistribCmdsTest, TestSolrQueryParserDefaultOperatorResource, AddBlockUpdateTest, TestSimpleQParserPlugin, MigrateRouteKeyTest, TestSolrCoreProperties, SpellCheckComponentTest, NotRequiredUniqueKeyTest, LeaderElectionIntegrationTest, TestAtomicUpdateErrorCases, TestIBSimilarityFactory, DocumentAnalysisRequestHandlerTest, FieldAnalysisRequestHandlerTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test]
[junit4] Completed on J1 in 77.57s, 1 test, 1 error <<< FAILURES!
[...truncated 620 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:453: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:433: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:491: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1304: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:937: There were test failures: 357 suites, 1572 tests, 1 error, 34 ignored (6 assumptions)
Total time: 69 minutes 6 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure