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/11/10 10:24:08 UTC
[JENKINS] Lucene-Solr-Tests-4.x-Java6 - Build # 2152 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/2152/
5 tests failed.
REGRESSION: org.apache.solr.cloud.SyncSliceTest.testDistribSearch
Error Message:
Test Setup Failure: shard1 should have just been set up to be inconsistent - but it's still consistent. Leader:http://127.0.0.1:59483/z/hh/collection1 Dead Guy:http://127.0.0.1:59476/z/hh/collection1skip list:[CloudJettyRunner [url=http://127.0.0.1:59479/z/hh/collection1], CloudJettyRunner [url=http://127.0.0.1:59479/z/hh/collection1]]
Stack Trace:
java.lang.AssertionError: Test Setup Failure: shard1 should have just been set up to be inconsistent - but it's still consistent. Leader:http://127.0.0.1:59483/z/hh/collection1 Dead Guy:http://127.0.0.1:59476/z/hh/collection1skip list:[CloudJettyRunner [url=http://127.0.0.1:59479/z/hh/collection1], CloudJettyRunner [url=http://127.0.0.1:59479/z/hh/collection1]]
at __randomizedtesting.SeedInfo.seed([8CB0AE12EBF0B69B:D56200A9CAFD6A7]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertNotNull(Assert.java:526)
at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:216)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
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:616)
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:679)
FAILED: org.apache.solr.cloud.DeleteReplicaTest.testDistribSearch
Error Message:
Invalid replica : core_node3 in shard/collection : shard1/delLiveColl
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Invalid replica : core_node3 in shard/collection : shard1/delLiveColl
at __randomizedtesting.SeedInfo.seed([8CB0AE12EBF0B69B:D56200A9CAFD6A7]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:464)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:268)
at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:640)
at org.apache.solr.cloud.DeleteReplicaTest.removeAndWaitForReplicaGone(DeleteReplicaTest.java:149)
at org.apache.solr.cloud.DeleteReplicaTest.deleteLiveReplicaTest(DeleteReplicaTest.java:135)
at org.apache.solr.cloud.DeleteReplicaTest.doTest(DeleteReplicaTest.java:115)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
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:616)
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:679)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.DeleteReplicaTest
Error Message:
ERROR: SolrZkClient opens=15 closes=14
Stack Trace:
java.lang.AssertionError: ERROR: SolrZkClient opens=15 closes=14
at __randomizedtesting.SeedInfo.seed([8CB0AE12EBF0B69B]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.SolrTestCaseJ4.endTrackingZkClients(SolrTestCaseJ4.java:343)
at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:135)
at sun.reflect.GeneratedMethodAccessor32.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:700)
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:679)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.DeleteReplicaTest
Error Message:
2 threads leaked from SUITE scope at org.apache.solr.cloud.DeleteReplicaTest: 1) Thread[id=3597, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[8CB0AE12EBF0B69B]-EventThread, state=WAITING, group=TGRP-DeleteReplicaTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:386) at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:491) 2) Thread[id=3596, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[8CB0AE12EBF0B69B]-SendThread(localhost:14546), state=RUNNABLE, group=TGRP-DeleteReplicaTest] at sun.nio.ch.KqueueArrayWrapper.kevent(Native Method) at sun.nio.ch.KqueueArrayWrapper.poll(KqueueArrayWrapper.java:146) at sun.nio.ch.KqueueSelectorImpl.doSelect(KqueueSelectorImpl.java:69) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:338) at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 2 threads leaked from SUITE scope at org.apache.solr.cloud.DeleteReplicaTest:
1) Thread[id=3597, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[8CB0AE12EBF0B69B]-EventThread, state=WAITING, group=TGRP-DeleteReplicaTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:386)
at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:491)
2) Thread[id=3596, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[8CB0AE12EBF0B69B]-SendThread(localhost:14546), state=RUNNABLE, group=TGRP-DeleteReplicaTest]
at sun.nio.ch.KqueueArrayWrapper.kevent(Native Method)
at sun.nio.ch.KqueueArrayWrapper.poll(KqueueArrayWrapper.java:146)
at sun.nio.ch.KqueueSelectorImpl.doSelect(KqueueSelectorImpl.java:69)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:338)
at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
at __randomizedtesting.SeedInfo.seed([8CB0AE12EBF0B69B]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.DeleteReplicaTest
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=3596, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[8CB0AE12EBF0B69B]-SendThread(localhost:14546), state=RUNNABLE, group=TGRP-DeleteReplicaTest] at sun.nio.ch.KqueueArrayWrapper.kevent(Native Method) at sun.nio.ch.KqueueArrayWrapper.poll(KqueueArrayWrapper.java:146) at sun.nio.ch.KqueueSelectorImpl.doSelect(KqueueSelectorImpl.java:69) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:338) at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=3596, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[8CB0AE12EBF0B69B]-SendThread(localhost:14546), state=RUNNABLE, group=TGRP-DeleteReplicaTest]
at sun.nio.ch.KqueueArrayWrapper.kevent(Native Method)
at sun.nio.ch.KqueueArrayWrapper.poll(KqueueArrayWrapper.java:146)
at sun.nio.ch.KqueueSelectorImpl.doSelect(KqueueSelectorImpl.java:69)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:338)
at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
at __randomizedtesting.SeedInfo.seed([8CB0AE12EBF0B69B]:0)
Build Log:
[...truncated 9812 lines...]
[junit4] Suite: org.apache.solr.cloud.SyncSliceTest
[junit4] 2> 1064327 T2612 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /z/hh
[junit4] 2> 1064332 T2612 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-SyncSliceTest-1384074338193
[junit4] 2> 1064333 T2612 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1064334 T2613 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1064435 T2612 oasc.ZkTestServer.run start zk server on port:59469
[junit4] 2> 1064436 T2612 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1064473 T2619 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@affb65 name:ZooKeeperConnection Watcher:127.0.0.1:59469 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1064473 T2612 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1064474 T2612 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1064491 T2612 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1064493 T2621 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@662dd161 name:ZooKeeperConnection Watcher:127.0.0.1:59469/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1064493 T2612 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1064494 T2612 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1064519 T2612 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1064635 T2612 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1064642 T2612 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1064647 T2612 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1064648 T2612 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1064699 T2612 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 1064700 T2612 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1064804 T2612 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1064805 T2612 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1064808 T2612 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1064808 T2612 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1064811 T2612 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1064812 T2612 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1064864 T2612 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1064864 T2612 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1064868 T2612 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 1064868 T2612 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 1064877 T2612 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1064877 T2612 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1064880 T2612 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1064881 T2612 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1064883 T2612 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1064884 T2612 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1064891 T2612 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1064892 T2612 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1065166 T2612 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1065170 T2612 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:59472
[junit4] 2> 1065171 T2612 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1065171 T2612 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1065172 T2612 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.SyncSliceTest-controljetty-1384074338757
[junit4] 2> 1065172 T2612 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-controljetty-1384074338757/'
[junit4] 2> 1065210 T2612 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1384074338757/solr.xml
[junit4] 2> 1065282 T2612 oasc.CoreContainer.<init> New CoreContainer 553975002
[junit4] 2> 1065283 T2612 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.SyncSliceTest-controljetty-1384074338757/]
[junit4] 2> 1065285 T2612 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1065285 T2612 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1065286 T2612 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1065286 T2612 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1065287 T2612 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1065287 T2612 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1065287 T2612 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1065288 T2612 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1065288 T2612 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1065295 T2612 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1065295 T2612 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1065296 T2612 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59469/solr
[junit4] 2> 1065296 T2612 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1065298 T2612 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1065329 T2632 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e745d25 name:ZooKeeperConnection Watcher:127.0.0.1:59469 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1065329 T2612 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1065341 T2612 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1065342 T2634 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2323bf05 name:ZooKeeperConnection Watcher:127.0.0.1:59469/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1065343 T2612 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1065345 T2612 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1065354 T2612 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1065358 T2612 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1065360 T2612 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59472_z%2Fhh
[junit4] 2> 1065369 T2612 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59472_z%2Fhh
[junit4] 2> 1065372 T2612 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1065390 T2612 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1065392 T2612 oasc.Overseer.start Overseer (id=90706695828275203-127.0.0.1:59472_z%2Fhh-n_0000000000) starting
[junit4] 2> 1065404 T2612 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1065413 T2636 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1065414 T2612 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1065416 T2612 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1065424 T2612 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1065426 T2635 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1065432 T2637 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1065432 T2637 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1065433 T2637 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1066930 T2635 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1066931 T2635 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:59472/z/hh",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:59472_z%2Fhh",
[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> 1066931 T2635 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 1066931 T2635 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1066948 T2634 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> 1067435 T2637 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1067435 T2637 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.SyncSliceTest-controljetty-1384074338757/collection1
[junit4] 2> 1067435 T2637 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1067436 T2637 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1067436 T2637 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1067437 T2637 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-controljetty-1384074338757/collection1/'
[junit4] 2> 1067439 T2637 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-controljetty-1384074338757/collection1/lib/README' to classloader
[junit4] 2> 1067439 T2637 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-controljetty-1384074338757/collection1/lib/classes/' to classloader
[junit4] 2> 1067501 T2637 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 1067562 T2637 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1067665 T2637 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1067676 T2637 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1068294 T2637 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1068295 T2637 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1068295 T2637 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1068308 T2637 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1068312 T2637 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1068326 T2637 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1068331 T2637 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1068335 T2637 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1068336 T2637 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1068336 T2637 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1068337 T2637 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1068338 T2637 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1068338 T2637 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1068338 T2637 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1068339 T2637 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.SyncSliceTest-controljetty-1384074338757/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1384074338192/control/data/
[junit4] 2> 1068339 T2637 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7345eca6
[junit4] 2> 1068340 T2637 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1384074338192/control/data
[junit4] 2> 1068340 T2637 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1384074338192/control/data/index/
[junit4] 2> 1068340 T2637 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1384074338192/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1068341 T2637 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1384074338192/control/data/index
[junit4] 2> 1068341 T2637 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=27, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1068342 T2637 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@3ca9cc99 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@509a9fd1),segFN=segments_1,generation=1}
[junit4] 2> 1068342 T2637 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1068346 T2637 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1068346 T2637 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1068346 T2637 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1068347 T2637 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1068347 T2637 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1068347 T2637 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1068348 T2637 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1068348 T2637 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1068348 T2637 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1068349 T2637 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1068349 T2637 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1068350 T2637 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1068350 T2637 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1068351 T2637 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1068351 T2637 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1068360 T2637 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1068366 T2637 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1068367 T2637 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1068367 T2637 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=29, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1068368 T2637 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@3ca9cc99 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@509a9fd1),segFN=segments_1,generation=1}
[junit4] 2> 1068368 T2637 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1068369 T2637 oass.SolrIndexSearcher.<init> Opening Searcher@6b476411 main
[junit4] 2> 1068372 T2638 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6b476411 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1068374 T2637 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1068374 T2637 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:59472/z/hh collection:control_collection shard:shard1
[junit4] 2> 1068375 T2637 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1068392 T2637 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1068396 T2637 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1068396 T2637 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1068396 T2637 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:59472/z/hh/collection1/
[junit4] 2> 1068396 T2637 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1068397 T2637 oasc.SyncStrategy.syncToMe http://127.0.0.1:59472/z/hh/collection1/ has no replicas
[junit4] 2> 1068397 T2637 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:59472/z/hh/collection1/ shard1
[junit4] 2> 1068397 T2637 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1068452 T2635 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1068468 T2634 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> 1068513 T2637 oasc.ZkController.register We are http://127.0.0.1:59472/z/hh/collection1/ and leader is http://127.0.0.1:59472/z/hh/collection1/
[junit4] 2> 1068513 T2637 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:59472/z/hh
[junit4] 2> 1068513 T2637 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1068513 T2637 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1068514 T2637 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1068515 T2637 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1068516 T2612 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4] 2> 1068517 T2612 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1068519 T2612 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1068521 T2641 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a1117d3 name:ZooKeeperConnection Watcher:127.0.0.1:59469/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1068521 T2612 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1068523 T2612 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1068526 T2612 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 1068810 T2612 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1068813 T2612 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:59476
[junit4] 2> 1068813 T2612 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1068814 T2612 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1068814 T2612 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1384074342386
[junit4] 2> 1068815 T2612 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1384074342386/'
[junit4] 2> 1068859 T2612 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1384074342386/solr.xml
[junit4] 2> 1068931 T2612 oasc.CoreContainer.<init> New CoreContainer 1195886624
[junit4] 2> 1068932 T2612 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1384074342386/]
[junit4] 2> 1068934 T2612 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1068934 T2612 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1068935 T2612 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1068935 T2612 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1068936 T2612 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1068936 T2612 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1068937 T2612 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1068937 T2612 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1068938 T2612 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1068944 T2612 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1068945 T2612 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1068945 T2612 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59469/solr
[junit4] 2> 1068946 T2612 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1068947 T2612 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1068950 T2652 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@39a3d16f name:ZooKeeperConnection Watcher:127.0.0.1:59469 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1068950 T2612 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1068966 T2612 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1068968 T2654 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4588e984 name:ZooKeeperConnection Watcher:127.0.0.1:59469/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1068968 T2612 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1068978 T2612 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1069981 T2612 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59476_z%2Fhh
[junit4] 2> 1069985 T2612 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59476_z%2Fhh
[junit4] 2> 1069985 T2635 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1069987 T2635 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:59472/z/hh",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:59472_z%2Fhh",
[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":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1070004 T2641 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1070004 T2654 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1070016 T2641 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> 1070016 T2654 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> 1070019 T2634 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1070019 T2634 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> 1070022 T2655 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1070022 T2655 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1070024 T2655 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1071521 T2635 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1071522 T2635 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:59476/z/hh",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:59476_z%2Fhh",
[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":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1071522 T2635 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1071523 T2635 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1071541 T2634 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> 1071541 T2654 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> 1071541 T2641 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> 1072026 T2655 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1072026 T2655 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1384074342386/collection1
[junit4] 2> 1072026 T2655 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1072027 T2655 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1072027 T2655 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1072028 T2655 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1384074342386/collection1/'
[junit4] 2> 1072030 T2655 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty1-1384074342386/collection1/lib/README' to classloader
[junit4] 2> 1072031 T2655 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty1-1384074342386/collection1/lib/classes/' to classloader
[junit4] 2> 1072092 T2655 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 1072153 T2655 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1072255 T2655 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1072266 T2655 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1072884 T2655 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1072885 T2655 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1072886 T2655 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1072898 T2655 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1072903 T2655 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1072916 T2655 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1072921 T2655 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1072925 T2655 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1072926 T2655 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1072927 T2655 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1072927 T2655 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1072928 T2655 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1072928 T2655 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1072929 T2655 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1072929 T2655 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1384074342386/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1384074338192/jetty1/
[junit4] 2> 1072929 T2655 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7345eca6
[junit4] 2> 1072930 T2655 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1384074338192/jetty1
[junit4] 2> 1072930 T2655 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1384074338192/jetty1/index/
[junit4] 2> 1072931 T2655 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1384074338192/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1072931 T2655 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1384074338192/jetty1/index
[junit4] 2> 1072932 T2655 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=27, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1072932 T2655 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@63666755 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1819232f),segFN=segments_1,generation=1}
[junit4] 2> 1072933 T2655 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1072937 T2655 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1072937 T2655 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1072938 T2655 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1072938 T2655 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1072938 T2655 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1072938 T2655 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1072939 T2655 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1072939 T2655 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1072940 T2655 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1072940 T2655 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1072941 T2655 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1072941 T2655 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1072942 T2655 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1072942 T2655 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1072943 T2655 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1072952 T2655 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1072957 T2655 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1072957 T2655 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1072958 T2655 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=29, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1072959 T2655 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@63666755 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1819232f),segFN=segments_1,generation=1}
[junit4] 2> 1072959 T2655 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1072959 T2655 oass.SolrIndexSearcher.<init> Opening Searcher@1beea61e main
[junit4] 2> 1072964 T2656 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1beea61e main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1072966 T2655 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1072966 T2655 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:59476/z/hh collection:collection1 shard:shard1
[junit4] 2> 1072968 T2655 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1072989 T2655 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1072992 T2655 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1072992 T2655 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1072992 T2655 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:59476/z/hh/collection1/
[junit4] 2> 1072992 T2655 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1072993 T2655 oasc.SyncStrategy.syncToMe http://127.0.0.1:59476/z/hh/collection1/ has no replicas
[junit4] 2> 1072993 T2655 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:59476/z/hh/collection1/ shard1
[junit4] 2> 1072993 T2655 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1073045 T2635 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1073060 T2634 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> 1073060 T2654 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> 1073060 T2641 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> 1073102 T2655 oasc.ZkController.register We are http://127.0.0.1:59476/z/hh/collection1/ and leader is http://127.0.0.1:59476/z/hh/collection1/
[junit4] 2> 1073102 T2655 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:59476/z/hh
[junit4] 2> 1073102 T2655 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1073102 T2655 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1073103 T2655 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1073104 T2655 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1073105 T2612 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4] 2> 1073106 T2612 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1073379 T2612 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1073382 T2612 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:59479
[junit4] 2> 1073383 T2612 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1073383 T2612 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1073384 T2612 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1384074346967
[junit4] 2> 1073384 T2612 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1384074346967/'
[junit4] 2> 1073423 T2612 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1384074346967/solr.xml
[junit4] 2> 1073503 T2612 oasc.CoreContainer.<init> New CoreContainer 1796544546
[junit4] 2> 1073504 T2612 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1384074346967/]
[junit4] 2> 1073506 T2612 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1073506 T2612 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1073507 T2612 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1073507 T2612 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1073508 T2612 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1073508 T2612 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1073509 T2612 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1073509 T2612 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1073510 T2612 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1073516 T2612 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1073517 T2612 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1073517 T2612 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59469/solr
[junit4] 2> 1073518 T2612 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1073519 T2612 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1073522 T2668 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@35e3971a name:ZooKeeperConnection Watcher:127.0.0.1:59469 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1073522 T2612 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1073537 T2612 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1073539 T2670 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3c90eb6c name:ZooKeeperConnection Watcher:127.0.0.1:59469/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1073540 T2612 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1073550 T2612 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1074554 T2612 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59479_z%2Fhh
[junit4] 2> 1074556 T2612 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59479_z%2Fhh
[junit4] 2> 1074560 T2641 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1074560 T2670 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1074560 T2654 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1074560 T2634 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1074578 T2635 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1074578 T2635 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:59476/z/hh",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:59476_z%2Fhh",
[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":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1074583 T2671 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1074583 T2671 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1074613 T2671 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1074631 T2635 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:59479/z/hh",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:59479_z%2Fhh",
[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":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1074631 T2635 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 1074631 T2635 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1074653 T2641 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> 1074653 T2670 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> 1074653 T2654 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> 1074653 T2634 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> 1075614 T2671 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1075614 T2671 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1384074346967/collection1
[junit4] 2> 1075614 T2671 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1075615 T2671 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1075615 T2671 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1075616 T2671 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1384074346967/collection1/'
[junit4] 2> 1075618 T2671 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty2-1384074346967/collection1/lib/classes/' to classloader
[junit4] 2> 1075619 T2671 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty2-1384074346967/collection1/lib/README' to classloader
[junit4] 2> 1075680 T2671 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 1075740 T2671 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1075843 T2671 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1075854 T2671 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1076473 T2671 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1076474 T2671 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1076475 T2671 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1076487 T2671 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1076491 T2671 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1076505 T2671 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1076510 T2671 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1076514 T2671 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1076515 T2671 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1076515 T2671 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1076516 T2671 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1076517 T2671 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1076517 T2671 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1076517 T2671 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1076518 T2671 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1384074346967/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1384074338192/jetty2/
[junit4] 2> 1076518 T2671 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7345eca6
[junit4] 2> 1076519 T2671 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1384074338192/jetty2
[junit4] 2> 1076519 T2671 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1384074338192/jetty2/index/
[junit4] 2> 1076519 T2671 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1384074338192/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1076520 T2671 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1384074338192/jetty2/index
[junit4] 2> 1076520 T2671 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=27, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1076521 T2671 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@5d3da059 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@370bbbb8),segFN=segments_1,generation=1}
[junit4] 2> 1076521 T2671 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1076525 T2671 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1076526 T2671 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1076526 T2671 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1076527 T2671 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1076527 T2671 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1076527 T2671 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1076528 T2671 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1076528 T2671 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1076528 T2671 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1076529 T2671 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1076530 T2671 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1076530 T2671 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1076530 T2671 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1076531 T2671 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1076531 T2671 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1076541 T2671 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1076546 T2671 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1076546 T2671 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1076547 T2671 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=29, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1076548 T2671 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@5d3da059 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@370bbbb8),segFN=segments_1,generation=1}
[junit4] 2> 1076548 T2671 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1076548 T2671 oass.SolrIndexSearcher.<init> Opening Searcher@6115fcda main
[junit4] 2> 1076552 T2672 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6115fcda main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1076555 T2671 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1076555 T2671 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:59479/z/hh collection:collection1 shard:shard1
[junit4] 2> 1076595 T2671 oasc.ZkController.register We are http://127.0.0.1:59479/z/hh/collection1/ and leader is http://127.0.0.1:59476/z/hh/collection1/
[junit4] 2> 1076595 T2671 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:59479/z/hh
[junit4] 2> 1076596 T2671 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 1076596 T2671 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C1078 name=collection1 org.apache.solr.core.SolrCore@38466057 url=http://127.0.0.1:59479/z/hh/collection1 node=127.0.0.1:59479_z%2Fhh C1078_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:59479/z/hh, core=collection1, node_name=127.0.0.1:59479_z%2Fhh}
[junit4] 2> 1076596 T2673 C1078 P59479 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 1076596 T2673 C1078 P59479 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 1076596 T2671 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1076597 T2673 C1078 P59479 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 1076597 T2673 C1078 P59479 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1076598 T2612 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4] 2> 1076598 T2612 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1076601 T2644 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 1076871 T2612 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1076874 T2612 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:59483
[junit4] 2> 1076875 T2612 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1076875 T2612 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1076876 T2612 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1384074350460
[junit4] 2> 1076876 T2612 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1384074350460/'
[junit4] 2> 1076915 T2612 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1384074350460/solr.xml
[junit4] 2> 1076995 T2612 oasc.CoreContainer.<init> New CoreContainer 700765648
[junit4] 2> 1076996 T2612 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1384074350460/]
[junit4] 2> 1076998 T2612 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1076998 T2612 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1076998 T2612 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1076999 T2612 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1076999 T2612 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1077000 T2612 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1077000 T2612 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1077001 T2612 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1077001 T2612 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1077008 T2612 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1077008 T2612 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1077009 T2612 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59469/solr
[junit4] 2> 1077009 T2612 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1077010 T2612 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1077013 T2685 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@39b1601c name:ZooKeeperConnection Watcher:127.0.0.1:59469 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1077014 T2612 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1077030 T2612 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1077032 T2687 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@37df5e23 name:ZooKeeperConnection Watcher:127.0.0.1:59469/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1077032 T2612 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1077043 T2612 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1077715 T2635 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1077716 T2635 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "base_url":"http://127.0.0.1:59479/z/hh",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:59479_z%2Fhh",
[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":"1",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 1077735 T2641 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> 1077735 T2654 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> 1077735 T2670 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> 1077735 T2634 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> 1077735 T2687 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> 1078047 T2612 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59483_z%2Fhh
[junit4] 2> 1078049 T2612 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59483_z%2Fhh
[junit4] 2> 1078051 T2641 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1078052 T2654 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1078052 T2634 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1078052 T2687 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1078052 T2670 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1078070 T2688 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1078070 T2688 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1078072 T2688 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1078603 T2644 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4] 2> 1078603 T2644 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=core_node2&state=recovering&nodeName=127.0.0.1:59479_z%252Fhh&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2002
[junit4] 2> 1079241 T2635 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1079242 T2635 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:59483/z/hh",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:59483_z%2Fhh",
[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":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1079242 T2635 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 1079242 T2635 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1079258 T2687 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1079258 T2654 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/
[...truncated too long message...]
lientCnxn$EventThread.run(ClientCnxn.java:491)
[junit4] 2>
[junit4] 2> 1793098 T3596 oaz.ClientCnxn$SendThread.run WARN Unexpected exception java.lang.InterruptedException: sleep interrupted
[junit4] 2> at java.lang.Thread.sleep(Native Method)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:984)
[junit4] 2>
[junit4] 2> 1793599 T3596 oazc.StaticHostProvider.next WARN Unexpected exception java.lang.InterruptedException: sleep interrupted
[junit4] 2> at java.lang.Thread.sleep(Native Method)
[junit4] 2> at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:86)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:937)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:993)
[junit4] 2>
[junit4] 2> 133835 T3509 ccr.ThreadLeakControl.tryToInterruptAll SEVERE There are still zombie threads that couldn't be terminated:
[junit4] 2> 1) Thread[id=3596, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[8CB0AE12EBF0B69B]-SendThread(localhost:14546), state=RUNNABLE, group=TGRP-DeleteReplicaTest]
[junit4] 2> at sun.nio.ch.KqueueArrayWrapper.kevent(Native Method)
[junit4] 2> at sun.nio.ch.KqueueArrayWrapper.poll(KqueueArrayWrapper.java:146)
[junit4] 2> at sun.nio.ch.KqueueSelectorImpl.doSelect(KqueueSelectorImpl.java:69)
[junit4] 2> at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
[junit4] 2> at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
[junit4] 2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:338)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=hu_HU, timezone=America/Knox_IN
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=3,free=147281760,total=507576320
[junit4] 2> NOTE: All tests run in this JVM: [TestFieldResource, TestDistributedSearch, TestJmxIntegration, ZkSolrClientTest, TestRandomFaceting, BasicZkTest, TestAnalyzedSuggestions, RequestHandlersTest, MinimalSchemaTest, InfoHandlerTest, SolrCoreCheckLockOnStartupTest, TestFoldingMultitermQuery, TestCSVResponseWriter, BJQParserTest, HdfsChaosMonkeySafeLeaderTest, SuggesterTSTTest, TestQueryTypes, SolrPluginUtilsTest, SolrTestCaseJ4Test, HardAutoCommitTest, BlockCacheTest, CoreMergeIndexesAdminHandlerTest, HdfsBasicDistributedZk2Test, TestZkChroot, TestDistributedGrouping, TestPartialUpdateDeduplication, OpenExchangeRatesOrgProviderTest, IndexBasedSpellCheckerTest, HighlighterConfigTest, PreAnalyzedFieldTest, DirectSolrSpellCheckerTest, DeleteInactiveReplicaTest, IndexSchemaRuntimeFieldTest, TestDynamicFieldResource, SolrRequestParserTest, TestNoOpRegenerator, AlternateDirectoryTest, TestDefaultSimilarityFactory, TestUpdate, PathHierarchyTokenizerFactoryTest, TestDFRSimilarityFactory, XmlUpdateRequestHandlerTest, FileUtilsTest, SolrCmdDistributorTest, TestArbitraryIndexDir, TestRangeQuery, PingRequestHandlerTest, TestFuzzyAnalyzedSuggestions, TestCodecSupport, TestHashPartitioner, MultiTermTest, TestAnalyzeInfixSuggestions, DocumentAnalysisRequestHandlerTest, TestFastOutputStream, TestNumberUtils, UniqFieldsUpdateProcessorFactoryTest, HdfsLockFactoryTest, NumericFieldsTest, TestSolrCoreProperties, TestCollapseQParserPlugin, TestAtomicUpdateErrorCases, TimeZoneUtilsTest, TestSolr4Spatial, TestIndexSearcher, TestIndexingPerformance, TestSolrQueryParserDefaultOperatorResource, DisMaxRequestHandlerTest, DocValuesMultiTest, DocValuesMissingTest, TestSchemaResource, SuggesterWFSTTest, TestRTGBase, LeaderElectionIntegrationTest, TestXIncludeConfig, HdfsCollectionsAPIDistributedZkTest, TestComponentsName, StatsComponentTest, TestSerializedLuceneMatchVersion, OpenCloseCoreStressTest, SignatureUpdateProcessorFactoryTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, CollectionsAPIDistributedZkTest, FullSolrCloudDistribCmdsTest, LeaderElectionTest, ZkCLITest, ShardRoutingCustomTest, AutoCommitTest, TestRecovery, TestStressReorder, SolrCoreTest, QueryElevationComponentTest, ConvertedLegacyTest, TestLazyCores, DirectUpdateHandlerTest, HighlighterTest, ShowFileRequestHandlerTest, CurrencyFieldOpenExchangeTest, SimplePostToolTest, TestCoreDiscovery, SpellCheckCollatorTest, SuggesterFSTTest, TestTrie, NoCacheHeaderTest, FieldMutatingUpdateProcessorTest, QueryEqualityTest, SortByFunctionTest, DistanceFunctionTest, XsltUpdateRequestHandlerTest, CacheHeaderTest, LukeRequestHandlerTest, TestReversedWildcardFilterFactory, TestOmitPositions, TermsComponentTest, TermVectorComponentTest, RequiredFieldsTest, TestSolrQueryParser, TestCollationField, BinaryUpdateRequestHandlerTest, SearchHandlerTest, TestBinaryResponseWriter, TestQuerySenderListener, TestQuerySenderNoQuery, BadComponentTest, TestStressRecovery, AssignTest, DeleteReplicaTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=DeleteReplicaTest -Dtests.seed=8CB0AE12EBF0B69B -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=hu_HU -Dtests.timezone=America/Knox_IN -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s J1 | DeleteReplicaTest (suite) <<<
[junit4] > Throwable #1: java.lang.AssertionError: ERROR: SolrZkClient opens=15 closes=14
[junit4] > at __randomizedtesting.SeedInfo.seed([8CB0AE12EBF0B69B]:0)
[junit4] > at org.apache.solr.SolrTestCaseJ4.endTrackingZkClients(SolrTestCaseJ4.java:343)
[junit4] > at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:135)
[junit4] > at java.lang.Thread.run(Thread.java:679)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: 2 threads leaked from SUITE scope at org.apache.solr.cloud.DeleteReplicaTest:
[junit4] > 1) Thread[id=3597, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[8CB0AE12EBF0B69B]-EventThread, state=WAITING, group=TGRP-DeleteReplicaTest]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
[junit4] > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
[junit4] > at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:386)
[junit4] > at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:491)
[junit4] > 2) Thread[id=3596, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[8CB0AE12EBF0B69B]-SendThread(localhost:14546), state=RUNNABLE, group=TGRP-DeleteReplicaTest]
[junit4] > at sun.nio.ch.KqueueArrayWrapper.kevent(Native Method)
[junit4] > at sun.nio.ch.KqueueArrayWrapper.poll(KqueueArrayWrapper.java:146)
[junit4] > at sun.nio.ch.KqueueSelectorImpl.doSelect(KqueueSelectorImpl.java:69)
[junit4] > at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
[junit4] > at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
[junit4] > at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:338)
[junit4] > at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4] > at __randomizedtesting.SeedInfo.seed([8CB0AE12EBF0B69B]:0)Throwable #3: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=3596, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[8CB0AE12EBF0B69B]-SendThread(localhost:14546), state=RUNNABLE, group=TGRP-DeleteReplicaTest]
[junit4] > at sun.nio.ch.KqueueArrayWrapper.kevent(Native Method)
[junit4] > at sun.nio.ch.KqueueArrayWrapper.poll(KqueueArrayWrapper.java:146)
[junit4] > at sun.nio.ch.KqueueSelectorImpl.doSelect(KqueueSelectorImpl.java:69)
[junit4] > at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
[junit4] > at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
[junit4] > at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:338)
[junit4] > at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4] > at __randomizedtesting.SeedInfo.seed([8CB0AE12EBF0B69B]:0)
[junit4] Completed on J1 in 133.88s, 1 test, 1 failure, 3 errors <<< FAILURES!
[...truncated 115 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:428: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:408: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/common-build.xml:483: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:1275: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:911: There were test failures: 335 suites, 1475 tests, 3 suite-level errors, 1 error, 1 failure, 164 ignored (6 assumptions)
Total time: 60 minutes 35 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure