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 2012/12/29 19:13:53 UTC
[JENKINS] Lucene-Solr-Tests-4.x-java7 - Build # 839 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-java7/839/
8 tests failed.
REGRESSION: org.apache.solr.cloud.BasicDistributedZkTest.testDistribSearch
Error Message:
No registered leader was found, collection:multiunload2 slice:shard1
Stack Trace:
org.apache.solr.common.SolrException: No registered leader was found, collection:multiunload2 slice:shard1
at org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:429)
at org.apache.solr.cloud.BasicDistributedZkTest.testStopAndStartCoresInOneInstance(BasicDistributedZkTest.java:678)
at org.apache.solr.cloud.BasicDistributedZkTest.doTest(BasicDistributedZkTest.java:339)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:794)
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:601)
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:722)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.BasicDistributedZkTest
Error Message:
Captured an uncaught exception in thread: Thread[id=1547, name=testExecutor-844-thread-11, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=1547, name=testExecutor-844-thread-11, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
at __randomizedtesting.SeedInfo.seed([4F77919082CFCB26]:0)
at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:642)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:722)
Caused by: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:413)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:640)
... 3 more
Caused by: org.apache.http.conn.ConnectTimeoutException: Connect to 127.0.0.1:11451 timed out
at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:125)
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:148)
at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:150)
at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:121)
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:575)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:425)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:820)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:754)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:732)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:352)
... 5 more
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.BasicDistributedZkTest
Error Message:
Captured an uncaught exception in thread: Thread[id=1540, name=testExecutor-844-thread-6, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=1540, name=testExecutor-844-thread-6, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
at __randomizedtesting.SeedInfo.seed([4F77919082CFCB26]:0)
at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:642)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:722)
Caused by: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:413)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:640)
... 3 more
Caused by: org.apache.http.conn.ConnectTimeoutException: Connect to 127.0.0.1:11451 timed out
at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:125)
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:148)
at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:150)
at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:121)
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:575)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:425)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:820)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:754)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:732)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:352)
... 5 more
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.BasicDistributedZkTest
Error Message:
Captured an uncaught exception in thread: Thread[id=1536, name=testExecutor-844-thread-2, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=1536, name=testExecutor-844-thread-2, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
at __randomizedtesting.SeedInfo.seed([4F77919082CFCB26]:0)
at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:642)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:722)
Caused by: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:413)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:640)
... 3 more
Caused by: org.apache.http.conn.ConnectTimeoutException: Connect to 127.0.0.1:11451 timed out
at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:125)
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:148)
at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:150)
at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:121)
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:575)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:425)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:820)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:754)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:732)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:352)
... 5 more
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.BasicDistributedZkTest
Error Message:
Captured an uncaught exception in thread: Thread[id=1542, name=testExecutor-844-thread-8, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=1542, name=testExecutor-844-thread-8, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
at __randomizedtesting.SeedInfo.seed([4F77919082CFCB26]:0)
at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:642)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:722)
Caused by: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:413)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:640)
... 3 more
Caused by: org.apache.http.conn.ConnectTimeoutException: Connect to 127.0.0.1:11451 timed out
at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:125)
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:148)
at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:150)
at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:121)
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:575)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:425)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:820)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:754)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:732)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:352)
... 5 more
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.BasicDistributedZkTest
Error Message:
Captured an uncaught exception in thread: Thread[id=1537, name=testExecutor-844-thread-3, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=1537, name=testExecutor-844-thread-3, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
at __randomizedtesting.SeedInfo.seed([4F77919082CFCB26]:0)
at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:642)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:722)
Caused by: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:413)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:640)
... 3 more
Caused by: org.apache.http.conn.ConnectTimeoutException: Connect to 127.0.0.1:11451 timed out
at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:125)
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:148)
at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:150)
at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:121)
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:575)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:425)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:820)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:754)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:732)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:352)
... 5 more
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.BasicDistributedZkTest
Error Message:
Captured an uncaught exception in thread: Thread[id=1538, name=testExecutor-844-thread-4, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=1538, name=testExecutor-844-thread-4, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
at __randomizedtesting.SeedInfo.seed([4F77919082CFCB26]:0)
at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:642)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:722)
Caused by: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:413)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:640)
... 3 more
Caused by: org.apache.http.conn.ConnectTimeoutException: Connect to 127.0.0.1:11451 timed out
at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:125)
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:148)
at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:150)
at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:121)
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:575)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:425)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:820)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:754)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:732)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:352)
... 5 more
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.BasicDistributedZkTest
Error Message:
Captured an uncaught exception in thread: Thread[id=1541, name=testExecutor-844-thread-7, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=1541, name=testExecutor-844-thread-7, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
at __randomizedtesting.SeedInfo.seed([4F77919082CFCB26]:0)
at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:642)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:722)
Caused by: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:413)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:640)
... 3 more
Caused by: org.apache.http.conn.ConnectTimeoutException: Connect to 127.0.0.1:11451 timed out
at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:125)
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:148)
at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:150)
at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:121)
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:575)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:425)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:820)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:754)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:732)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:352)
... 5 more
Build Log:
[...truncated 8920 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
[junit4:junit4] 2> 0 T973 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 4 T973 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZkTest-1356803392805
[junit4:junit4] 2> 5 T973 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 6 T974 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 8 T974 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4] 2> 9 T974 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4] 2> 9 T974 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4] 2> 9 T974 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> 10 T974 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4] 2> 107 T973 oasc.ZkTestServer.run start zk server on port:60632
[junit4:junit4] 2> 107 T973 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60632 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@6798f9f3
[junit4:junit4] 2> 108 T973 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 109 T979 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:60632. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 109 T979 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:60632, initiating session
[junit4:junit4] 2> 109 T975 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:18964
[junit4:junit4] 2> 110 T975 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:18964
[junit4:junit4] 2> 110 T977 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4] 2> 112 T977 oazs.ZooKeeperServer.finishSessionInit Established session 0x13be7c8c52b0000 with negotiated timeout 10000 for client /140.211.11.196:18964
[junit4:junit4] 2> 112 T979 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:60632, sessionid = 0x13be7c8c52b0000, negotiated timeout = 10000
[junit4:junit4] 2> 112 T980 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6798f9f3 name:ZooKeeperConnection Watcher:127.0.0.1:60632 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 113 T973 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 113 T973 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 116 T978 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13be7c8c52b0000
[junit4:junit4] 2> 123 T980 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 124 T975 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:18964 which had sessionid 0x13be7c8c52b0000
[junit4:junit4] 2> 123 T973 oaz.ZooKeeper.close Session: 0x13be7c8c52b0000 closed
[junit4:junit4] 2> 124 T973 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60632/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@14f86c5f
[junit4:junit4] 2> 125 T973 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 126 T981 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:60632. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 126 T981 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:60632, initiating session
[junit4:junit4] 2> 126 T975 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:17231
[junit4:junit4] 2> 127 T975 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:17231
[junit4:junit4] 2> 128 T977 oazs.ZooKeeperServer.finishSessionInit Established session 0x13be7c8c52b0001 with negotiated timeout 10000 for client /140.211.11.196:17231
[junit4:junit4] 2> 128 T981 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:60632, sessionid = 0x13be7c8c52b0001, negotiated timeout = 10000
[junit4:junit4] 2> 128 T982 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14f86c5f name:ZooKeeperConnection Watcher:127.0.0.1:60632/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 129 T973 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 129 T973 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 139 T973 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 142 T973 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 145 T973 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 153 T973 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 154 T973 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 160 T973 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 161 T973 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 266 T973 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 267 T973 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 270 T973 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 271 T973 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 281 T973 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 282 T973 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 288 T973 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 289 T973 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 292 T973 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 293 T973 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 296 T973 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 297 T973 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 300 T973 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 301 T973 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 304 T978 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13be7c8c52b0001
[junit4:junit4] 2> 311 T982 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 311 T973 oaz.ZooKeeper.close Session: 0x13be7c8c52b0001 closed
[junit4:junit4] 2> 311 T975 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:17231 which had sessionid 0x13be7c8c52b0001
[junit4:junit4] 2> 443 T973 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 448 T973 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:26760
[junit4:junit4] 2> 449 T973 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 449 T973 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1356803393112
[junit4:junit4] 2> 449 T973 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1356803393112/'
[junit4:junit4] 2> 482 T973 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 482 T973 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 483 T973 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1356803393112
[junit4:junit4] 2> 483 T973 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1356803393112/solr.xml
[junit4:junit4] 2> 483 T973 oasc.CoreContainer.<init> New CoreContainer 1903228422
[junit4:junit4] 2> 484 T973 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1356803393112/'
[junit4:junit4] 2> 485 T973 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1356803393112/'
[junit4:junit4] 2> 507 T973 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 30000
[junit4:junit4] 2> 508 T973 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 508 T973 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 508 T973 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 509 T973 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 509 T973 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 509 T973 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 510 T973 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 510 T973 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 511 T973 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=30000&connTimeout=15000&retry=false
[junit4:junit4] 2> 526 T973 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 540 T973 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:60632/solr
[junit4:junit4] 2> 541 T973 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 541 T973 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60632 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@65bf6c74
[junit4:junit4] 2> 542 T973 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 543 T992 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:60632. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 543 T992 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:60632, initiating session
[junit4:junit4] 2> 544 T975 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:58586
[junit4:junit4] 2> 544 T975 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:58586
[junit4:junit4] 2> 545 T977 oazs.ZooKeeperServer.finishSessionInit Established session 0x13be7c8c52b0002 with negotiated timeout 20000 for client /140.211.11.196:58586
[junit4:junit4] 2> 545 T992 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:60632, sessionid = 0x13be7c8c52b0002, negotiated timeout = 20000
[junit4:junit4] 2> 546 T993 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@65bf6c74 name:ZooKeeperConnection Watcher:127.0.0.1:60632 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 546 T973 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 547 T978 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13be7c8c52b0002
[junit4:junit4] 2> 548 T993 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 548 T973 oaz.ZooKeeper.close Session: 0x13be7c8c52b0002 closed
[junit4:junit4] 2> 548 T975 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:58586 which had sessionid 0x13be7c8c52b0002
[junit4:junit4] 2> 548 T973 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=15000&connTimeout=30000
[junit4:junit4] 2> 557 T973 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60632/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@3f0a8297
[junit4:junit4] 2> 557 T973 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 558 T994 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:60632. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 558 T994 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:60632, initiating session
[junit4:junit4] 2> 558 T975 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:44467
[junit4:junit4] 2> 559 T975 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:44467
[junit4:junit4] 2> 560 T977 oazs.ZooKeeperServer.finishSessionInit Established session 0x13be7c8c52b0003 with negotiated timeout 20000 for client /140.211.11.196:44467
[junit4:junit4] 2> 560 T994 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:60632, sessionid = 0x13be7c8c52b0003, negotiated timeout = 20000
[junit4:junit4] 2> 560 T995 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3f0a8297 name:ZooKeeperConnection Watcher:127.0.0.1:60632/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 560 T973 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 562 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 571 T973 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 573 T973 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:26760_
[junit4:junit4] 2> 574 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0003 type:delete cxid:0x7 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:26760_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:26760_
[junit4:junit4] 2> 575 T973 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:26760_
[junit4:junit4] 2> 585 T973 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 596 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0003 type:delete cxid:0x15 zxid:0x21 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4] 2> 598 T973 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 607 T973 oasc.Overseer.start Overseer (id=88919467151261699-127.0.0.1:26760_-n_0000000000) starting
[junit4:junit4] 2> 608 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0003 type:create cxid:0x1a zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 609 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0003 type:create cxid:0x1b zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 611 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0003 type:create cxid:0x1c zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 620 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0003 type:create cxid:0x1d zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 621 T997 oasc.OverseerCollectionProcessor.run Process current queue of collection messages
[junit4:junit4] 2> 622 T973 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 625 T973 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 627 T996 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 631 T998 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1356803393112/collection1
[junit4:junit4] 2> 631 T998 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 632 T998 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 632 T998 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 633 T998 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1356803393112/collection1/'
[junit4:junit4] 2> 634 T998 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1356803393112/collection1/lib/README' to classloader
[junit4:junit4] 2> 634 T998 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1356803393112/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 679 T998 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4] 2> 730 T998 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 831 T998 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 835 T998 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 1283 T998 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1291 T998 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1294 T998 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1305 T998 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1309 T998 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1313 T998 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1314 T998 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1315 T998 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1356803393112/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/control/data/
[junit4:junit4] 2> 1315 T998 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e5c2ec4
[junit4:junit4] 2> 1316 T998 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 1339 T998 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/control/data forceNew:false
[junit4:junit4] 2> 1340 T998 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/control/data
[junit4:junit4] 2> 1340 T998 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/control/data/index/
[junit4:junit4] 2> 1341 T998 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1342 T998 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/control/data/index forceNew:false
[junit4:junit4] 2> 1346 T998 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c8a95f1),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 1347 T998 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 1347 T998 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/control/data/index
[junit4:junit4] 2> 1348 T998 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 1349 T998 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1349 T998 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 1350 T998 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1350 T998 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 1351 T998 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1351 T998 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1351 T998 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1351 T998 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1352 T998 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1352 T998 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 1352 T998 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 1353 T998 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1353 T998 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 1353 T998 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 1353 T998 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 1354 T998 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1354 T998 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1354 T998 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1355 T998 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1355 T998 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1355 T998 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1356 T998 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1356 T998 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1356 T998 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1357 T998 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 1357 T998 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 1365 T998 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1369 T998 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 1370 T998 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 1372 T998 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/control/data
[junit4:junit4] 2> 1373 T998 oass.SolrIndexSearcher.<init> Opening Searcher@3900fc4 main
[junit4:junit4] 2> 1374 T998 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1374 T998 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1374 T998 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 1380 T998 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 1432 T999 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3900fc4 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1436 T998 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1437 T998 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1438 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0003 type:create cxid:0x53 zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4] 2> 1633 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1633 T996 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "node_name":"127.0.0.1:26760_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:26760"}
[junit4:junit4] 2> 1634 T996 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 1634 T996 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 1635 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0003 type:create cxid:0x5b zxid:0x2c txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4] 2> 1727 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 2449 T998 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2449 T998 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:26760 collection:control_collection shard:shard1
[junit4:junit4] 2> 2450 T998 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2495 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0003 type:delete cxid:0x78 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4] 2> 2496 T998 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2496 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0003 type:create cxid:0x79 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 2506 T998 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2506 T998 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2506 T998 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:26760/collection1/
[junit4:junit4] 2> 2506 T998 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2506 T998 oasc.SyncStrategy.syncToMe http://127.0.0.1:26760/collection1/ has no replicas
[junit4:junit4] 2> 2507 T998 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:26760/collection1/
[junit4:junit4] 2> 2507 T998 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 2511 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0003 type:create cxid:0x83 zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 2758 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2774 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 2826 T998 oasc.ZkController.register We are http://127.0.0.1:26760/collection1/ and leader is http://127.0.0.1:26760/collection1/
[junit4:junit4] 2> 2826 T998 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:26760
[junit4:junit4] 2> 2826 T998 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 2827 T998 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 2827 T998 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2829 T998 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2830 T973 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 2831 T973 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2831 T973 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2844 T973 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 2854 T973 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60632/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@57ee1887
[junit4:junit4] 2> 2855 T973 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2855 T1000 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:60632. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 2855 T1000 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:60632, initiating session
[junit4:junit4] 2> 2856 T975 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:12519
[junit4:junit4] 2> 2856 T975 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:12519
[junit4:junit4] 2> 2857 T977 oazs.ZooKeeperServer.finishSessionInit Established session 0x13be7c8c52b0004 with negotiated timeout 10000 for client /140.211.11.196:12519
[junit4:junit4] 2> 2857 T1000 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:60632, sessionid = 0x13be7c8c52b0004, negotiated timeout = 10000
[junit4:junit4] 2> 2857 T1001 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@57ee1887 name:ZooKeeperConnection Watcher:127.0.0.1:60632/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2858 T973 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2859 T973 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2860 T973 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 3021 T973 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 3024 T973 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:57687
[junit4:junit4] 2> 3025 T973 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 3026 T973 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1356803395661
[junit4:junit4] 2> 3026 T973 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1356803395661/'
[junit4:junit4] 2> 3068 T973 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 3069 T973 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 3069 T973 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1356803395661
[junit4:junit4] 2> 3070 T973 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1356803395661/solr.xml
[junit4:junit4] 2> 3070 T973 oasc.CoreContainer.<init> New CoreContainer 424796969
[junit4:junit4] 2> 3071 T973 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1356803395661/'
[junit4:junit4] 2> 3071 T973 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1356803395661/'
[junit4:junit4] 2> 3101 T973 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 30000
[junit4:junit4] 2> 3102 T973 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 3103 T973 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 3103 T973 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 3103 T973 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 3104 T973 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 3104 T973 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 3105 T973 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 3105 T973 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 3106 T973 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=30000&connTimeout=15000&retry=false
[junit4:junit4] 2> 3125 T973 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 3148 T973 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:60632/solr
[junit4:junit4] 2> 3149 T973 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 3149 T973 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60632 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@15ab64cf
[junit4:junit4] 2> 3150 T973 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3151 T1011 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:60632. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3152 T1011 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:60632, initiating session
[junit4:junit4] 2> 3152 T975 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:62925
[junit4:junit4] 2> 3152 T975 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:62925
[junit4:junit4] 2> 3154 T977 oazs.ZooKeeperServer.finishSessionInit Established session 0x13be7c8c52b0005 with negotiated timeout 20000 for client /140.211.11.196:62925
[junit4:junit4] 2> 3154 T1011 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:60632, sessionid = 0x13be7c8c52b0005, negotiated timeout = 20000
[junit4:junit4] 2> 3155 T1012 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15ab64cf name:ZooKeeperConnection Watcher:127.0.0.1:60632 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3155 T973 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3156 T978 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13be7c8c52b0005
[junit4:junit4] 2> 3170 T1012 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 3170 T975 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:62925 which had sessionid 0x13be7c8c52b0005
[junit4:junit4] 2> 3170 T973 oaz.ZooKeeper.close Session: 0x13be7c8c52b0005 closed
[junit4:junit4] 2> 3171 T973 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=15000&connTimeout=30000
[junit4:junit4] 2> 3181 T973 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60632/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@72b832c9
[junit4:junit4] 2> 3182 T973 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3182 T1013 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:60632. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3183 T1013 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:60632, initiating session
[junit4:junit4] 2> 3183 T975 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:24924
[junit4:junit4] 2> 3183 T975 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:24924
[junit4:junit4] 2> 3185 T977 oazs.ZooKeeperServer.finishSessionInit Established session 0x13be7c8c52b0006 with negotiated timeout 20000 for client /140.211.11.196:24924
[junit4:junit4] 2> 3185 T1013 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:60632, sessionid = 0x13be7c8c52b0006, negotiated timeout = 20000
[junit4:junit4] 2> 3185 T1014 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@72b832c9 name:ZooKeeperConnection Watcher:127.0.0.1:60632/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3185 T973 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3186 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0006 type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3188 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0006 type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3195 T973 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57687_
[junit4:junit4] 2> 3196 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0006 type:delete cxid:0x4 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:57687_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:57687_
[junit4:junit4] 2> 3197 T973 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57687_
[junit4:junit4] 2> 3199 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 3200 T1001 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 3208 T995 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 3209 T973 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 3215 T1015 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1356803395661/collection1
[junit4:junit4] 2> 3215 T1015 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 3216 T1015 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 3216 T1015 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 3217 T1015 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1356803395661/collection1/'
[junit4:junit4] 2> 3219 T1015 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1356803395661/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 3219 T1015 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1356803395661/collection1/lib/README' to classloader
[junit4:junit4] 2> 3272 T1015 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4] 2> 3287 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3288 T996 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "node_name":"127.0.0.1:26760_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:26760"}
[junit4:junit4] 2> 3302 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 3302 T1001 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 3302 T1014 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 3341 T1015 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 3442 T1015 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 3451 T1015 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 3981 T1015 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 3990 T1015 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 3992 T1015 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 4006 T1015 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 4010 T1015 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 4014 T1015 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 4015 T1015 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 4017 T1015 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1356803395661/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty1/
[junit4:junit4] 2> 4017 T1015 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e5c2ec4
[junit4:junit4] 2> 4017 T1015 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 4018 T1015 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty1 forceNew:false
[junit4:junit4] 2> 4019 T1015 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty1
[junit4:junit4] 2> 4019 T1015 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty1/index/
[junit4:junit4] 2> 4019 T1015 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 4020 T1015 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty1/index forceNew:false
[junit4:junit4] 2> 4024 T1015 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@210f93dd),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 4025 T1015 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 4025 T1015 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty1/index
[junit4:junit4] 2> 4026 T1015 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 4028 T1015 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 4028 T1015 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 4028 T1015 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 4028 T1015 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 4029 T1015 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 4029 T1015 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 4030 T1015 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 4030 T1015 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 4030 T1015 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 4031 T1015 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 4031 T1015 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 4032 T1015 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 4032 T1015 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 4032 T1015 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 4033 T1015 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 4033 T1015 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 4034 T1015 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 4034 T1015 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 4035 T1015 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 4035 T1015 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 4036 T1015 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 4037 T1015 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 4037 T1015 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 4037 T1015 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 4038 T1015 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 4038 T1015 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 4047 T1015 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 4051 T1015 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 4052 T1015 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 4054 T1015 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty1
[junit4:junit4] 2> 4055 T1015 oass.SolrIndexSearcher.<init> Opening Searcher@7620847a main
[junit4:junit4] 2> 4056 T1015 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 4057 T1015 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 4057 T1015 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 4063 T1015 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 4120 T1016 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7620847a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 4125 T1015 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 4126 T1015 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 4309 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 4310 T996 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:57687_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57687"}
[junit4:junit4] 2> 4310 T996 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 4310 T996 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 4323 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 4323 T1001 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 4323 T1014 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 5129 T1015 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 5129 T1015 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57687 collection:collection1 shard:shard1
[junit4:junit4] 2> 5130 T1015 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 5146 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0006 type:delete cxid:0x45 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4] 2> 5147 T1015 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 5147 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0006 type:create cxid:0x46 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 5149 T1015 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 5149 T1015 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 5149 T1015 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57687/collection1/
[junit4:junit4] 2> 5150 T1015 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 5150 T1015 oasc.SyncStrategy.syncToMe http://127.0.0.1:57687/collection1/ has no replicas
[junit4:junit4] 2> 5150 T1015 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57687/collection1/
[junit4:junit4] 2> 5150 T1015 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 5154 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0006 type:create cxid:0x50 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 5329 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 5346 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 5346 T1001 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 5346 T1014 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 5359 T1015 oasc.ZkController.register We are http://127.0.0.1:57687/collection1/ and leader is http://127.0.0.1:57687/collection1/
[junit4:junit4] 2> 5359 T1015 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57687
[junit4:junit4] 2> 5359 T1015 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 5359 T1015 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 5359 T1015 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 5361 T1015 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 5362 T973 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 5362 T973 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 5363 T973 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 5508 T973 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 5510 T973 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:51111
[junit4:junit4] 2> 5511 T973 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 5511 T973 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1356803398179
[junit4:junit4] 2> 5512 T973 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1356803398179/'
[junit4:junit4] 2> 5542 T973 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 5542 T973 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 5543 T973 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1356803398179
[junit4:junit4] 2> 5543 T973 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1356803398179/solr.xml
[junit4:junit4] 2> 5543 T973 oasc.CoreContainer.<init> New CoreContainer 1491485441
[junit4:junit4] 2> 5544 T973 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1356803398179/'
[junit4:junit4] 2> 5544 T973 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1356803398179/'
[junit4:junit4] 2> 5566 T973 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 30000
[junit4:junit4] 2> 5566 T973 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 5567 T973 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 5567 T973 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 5567 T973 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 5568 T973 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 5568 T973 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 5568 T973 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 5569 T973 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 5569 T973 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=30000&connTimeout=15000&retry=false
[junit4:junit4] 2> 5582 T973 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 5596 T973 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:60632/solr
[junit4:junit4] 2> 5597 T973 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 5597 T973 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60632 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@53f8e695
[junit4:junit4] 2> 5598 T973 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 5598 T1026 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:60632. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 5599 T1026 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:60632, initiating session
[junit4:junit4] 2> 5599 T975 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:10542
[junit4:junit4] 2> 5599 T975 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:10542
[junit4:junit4] 2> 5601 T977 oazs.ZooKeeperServer.finishSessionInit Established session 0x13be7c8c52b0007 with negotiated timeout 20000 for client /140.211.11.196:10542
[junit4:junit4] 2> 5601 T1026 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:60632, sessionid = 0x13be7c8c52b0007, negotiated timeout = 20000
[junit4:junit4] 2> 5602 T1027 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@53f8e695 name:ZooKeeperConnection Watcher:127.0.0.1:60632 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 5602 T973 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 5603 T978 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13be7c8c52b0007
[junit4:junit4] 2> 5615 T1027 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 5615 T975 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:10542 which had sessionid 0x13be7c8c52b0007
[junit4:junit4] 2> 5615 T973 oaz.ZooKeeper.close Session: 0x13be7c8c52b0007 closed
[junit4:junit4] 2> 5616 T973 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=15000&connTimeout=30000
[junit4:junit4] 2> 5623 T973 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60632/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1ab37ba0
[junit4:junit4] 2> 5623 T973 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 5624 T1028 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:60632. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 5624 T1028 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:60632, initiating session
[junit4:junit4] 2> 5624 T975 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:24100
[junit4:junit4] 2> 5625 T975 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:24100
[junit4:junit4] 2> 5626 T977 oazs.ZooKeeperServer.finishSessionInit Established session 0x13be7c8c52b0008 with negotiated timeout 20000 for client /140.211.11.196:24100
[junit4:junit4] 2> 5626 T1028 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:60632, sessionid = 0x13be7c8c52b0008, negotiated timeout = 20000
[junit4:junit4] 2> 5626 T1029 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ab37ba0 name:ZooKeeperConnection Watcher:127.0.0.1:60632/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 5626 T973 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 5627 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0008 type:create cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 5633 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0008 type:create cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 5635 T973 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51111_
[junit4:junit4] 2> 5635 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0008 type:delete cxid:0x4 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:51111_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:51111_
[junit4:junit4] 2> 5636 T973 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51111_
[junit4:junit4] 2> 5644 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 5645 T1014 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 5645 T1001 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 5645 T1001 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 5646 T995 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 5646 T1014 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 5648 T973 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 5653 T1030 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1356803398179/collection1
[junit4:junit4] 2> 5653 T1030 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 5654 T1030 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 5654 T1030 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 5655 T1030 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1356803398179/collection1/'
[junit4:junit4] 2> 5656 T1030 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1356803398179/collection1/lib/README' to classloader
[junit4:junit4] 2> 5656 T1030 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1356803398179/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 5700 T1030 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4] 2> 5779 T1030 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 5860 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 5861 T996 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:57687_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57687"}
[junit4:junit4] 2> 5875 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 5875 T1014 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 5875 T1001 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 5880 T1030 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 5880 T1029 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 5900 T1030 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 6325 T1030 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 6332 T1030 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 6335 T1030 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 6348 T1030 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 6353 T1030 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 6357 T1030 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 6358 T1030 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 6359 T1030 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1356803398179/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty2/
[junit4:junit4] 2> 6360 T1030 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e5c2ec4
[junit4:junit4] 2> 6360 T1030 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 6361 T1030 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty2 forceNew:false
[junit4:junit4] 2> 6361 T1030 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty2
[junit4:junit4] 2> 6361 T1030 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty2/index/
[junit4:junit4] 2> 6362 T1030 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 6363 T1030 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty2/index forceNew:false
[junit4:junit4] 2> 6367 T1030 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@368990f6),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 6367 T1030 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 6368 T1030 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty2/index
[junit4:junit4] 2> 6368 T1030 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 6370 T1030 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 6370 T1030 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 6371 T1030 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 6371 T1030 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 6372 T1030 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 6372 T1030 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 6372 T1030 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 6373 T1030 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 6373 T1030 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 6373 T1030 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 6374 T1030 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 6374 T1030 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 6374 T1030 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 6375 T1030 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 6375 T1030 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 6375 T1030 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 6376 T1030 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 6376 T1030 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 6376 T1030 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 6377 T1030 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 6377 T1030 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 6377 T1030 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 6378 T1030 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 6378 T1030 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 6379 T1030 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 6379 T1030 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 6388 T1030 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 6392 T1030 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 6406 T1030 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 6408 T1030 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty2
[junit4:junit4] 2> 6410 T1030 oass.SolrIndexSearcher.<init> Opening Searcher@7581e357 main
[junit4:junit4] 2> 6411 T1030 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 6411 T1030 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 6411 T1030 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 6417 T1030 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 6482 T1031 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7581e357 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 6487 T1030 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 6487 T1030 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 6882 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 6883 T996 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:51111_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:51111"}
[junit4:junit4] 2> 6883 T996 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 6883 T996 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 6903 T1001 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 6903 T1014 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 6903 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 6903 T1029 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 7493 T1030 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 7493 T1030 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51111 collection:collection1 shard:shard2
[junit4:junit4] 2> 7494 T1030 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 7516 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0008 type:delete cxid:0x44 zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard2 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard2
[junit4:junit4] 2> 7517 T1030 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 7518 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0008 type:create cxid:0x45 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 7531 T1030 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 7531 T1030 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 7532 T1030 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51111/collection1/
[junit4:junit4] 2> 7532 T1030 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 7532 T1030 oasc.SyncStrategy.syncToMe http://127.0.0.1:51111/collection1/ has no replicas
[junit4:junit4] 2> 7532 T1030 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51111/collection1/
[junit4:junit4] 2> 7532 T1030 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 7536 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b0008 type:create cxid:0x4e zxid:0x82 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 7914 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 7936 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 7936 T1014 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 7936 T1029 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 7936 T1001 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 7958 T1030 oasc.ZkController.register We are http://127.0.0.1:51111/collection1/ and leader is http://127.0.0.1:51111/collection1/
[junit4:junit4] 2> 7958 T1030 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51111
[junit4:junit4] 2> 7958 T1030 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 7959 T1030 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 7959 T1030 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 7960 T1030 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 7961 T973 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 7962 T973 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 7962 T973 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 8139 T973 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 8142 T973 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:11451
[junit4:junit4] 2> 8143 T973 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 8143 T973 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1356803400774
[junit4:junit4] 2> 8144 T973 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1356803400774/'
[junit4:junit4] 2> 8188 T973 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 8189 T973 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 8189 T973 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1356803400774
[junit4:junit4] 2> 8189 T973 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1356803400774/solr.xml
[junit4:junit4] 2> 8190 T973 oasc.CoreContainer.<init> New CoreContainer 968106207
[junit4:junit4] 2> 8191 T973 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1356803400774/'
[junit4:junit4] 2> 8191 T973 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1356803400774/'
[junit4:junit4] 2> 8221 T973 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 30000
[junit4:junit4] 2> 8222 T973 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 8222 T973 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 8222 T973 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 8223 T973 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 8223 T973 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 8223 T973 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 8224 T973 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 8224 T973 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 8224 T973 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=30000&connTimeout=15000&retry=false
[junit4:junit4] 2> 8241 T973 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 8258 T973 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:60632/solr
[junit4:junit4] 2> 8258 T973 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 8259 T973 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60632 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@6d4485c4
[junit4:junit4] 2> 8260 T973 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8260 T1041 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:60632. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 8261 T1041 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:60632, initiating session
[junit4:junit4] 2> 8261 T975 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:50076
[junit4:junit4] 2> 8261 T975 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:50076
[junit4:junit4] 2> 8264 T977 oazs.ZooKeeperServer.finishSessionInit Established session 0x13be7c8c52b0009 with negotiated timeout 20000 for client /140.211.11.196:50076
[junit4:junit4] 2> 8264 T1041 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:60632, sessionid = 0x13be7c8c52b0009, negotiated timeout = 20000
[junit4:junit4] 2> 8264 T1042 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6d4485c4 name:ZooKeeperConnection Watcher:127.0.0.1:60632 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8264 T973 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8266 T978 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13be7c8c52b0009
[junit4:junit4] 2> 8279 T1042 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 8279 T973 oaz.ZooKeeper.close Session: 0x13be7c8c52b0009 closed
[junit4:junit4] 2> 8279 T975 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:50076 which had sessionid 0x13be7c8c52b0009
[junit4:junit4] 2> 8280 T973 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=15000&connTimeout=30000
[junit4:junit4] 2> 8289 T973 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60632/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@3cdb519f
[junit4:junit4] 2> 8289 T973 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8290 T1043 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:60632. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 8290 T1043 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:60632, initiating session
[junit4:junit4] 2> 8290 T975 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:16686
[junit4:junit4] 2> 8291 T975 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:16686
[junit4:junit4] 2> 8293 T977 oazs.ZooKeeperServer.finishSessionInit Established session 0x13be7c8c52b000a with negotiated timeout 20000 for client /140.211.11.196:16686
[junit4:junit4] 2> 8293 T1043 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:60632, sessionid = 0x13be7c8c52b000a, negotiated timeout = 20000
[junit4:junit4] 2> 8293 T1044 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3cdb519f name:ZooKeeperConnection Watcher:127.0.0.1:60632/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8293 T973 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8294 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b000a type:create cxid:0x1 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8296 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b000a type:create cxid:0x2 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8303 T973 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:11451_
[junit4:junit4] 2> 8304 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b000a type:delete cxid:0x4 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:11451_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:11451_
[junit4:junit4] 2> 8305 T973 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:11451_
[junit4:junit4] 2> 8307 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 8307 T1014 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 8307 T1029 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 8313 T1001 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 8314 T1001 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 8315 T995 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 8315 T1014 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 8317 T1029 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 8319 T973 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 8328 T1045 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1356803400774/collection1
[junit4:junit4] 2> 8328 T1045 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 8329 T1045 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 8329 T1045 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 8330 T1045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1356803400774/collection1/'
[junit4:junit4] 2> 8331 T1045 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1356803400774/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 8332 T1045 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1356803400774/collection1/lib/README' to classloader
[junit4:junit4] 2> 8385 T1045 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4] 2> 8446 T1045 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 8456 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8457 T996 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:51111_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:51111"}
[junit4:junit4] 2> 8516 T1014 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 8516 T1029 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 8516 T1001 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 8516 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 8547 T1045 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 8547 T1044 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 8554 T1045 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 9285 T1045 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 9297 T1045 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 9301 T1045 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 9316 T1045 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 9322 T1045 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 9327 T1045 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 9328 T1045 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 9330 T1045 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1356803400774/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/
[junit4:junit4] 2> 9330 T1045 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e5c2ec4
[junit4:junit4] 2> 9331 T1045 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 9332 T1045 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3 forceNew:false
[junit4:junit4] 2> 9332 T1045 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3
[junit4:junit4] 2> 9333 T1045 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/index/
[junit4:junit4] 2> 9333 T1045 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 9334 T1045 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/index forceNew:false
[junit4:junit4] 2> 9343 T1045 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@24ba1205),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 9343 T1045 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 9344 T1045 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/index
[junit4:junit4] 2> 9345 T1045 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 9347 T1045 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 9348 T1045 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 9348 T1045 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 9348 T1045 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 9349 T1045 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 9349 T1045 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 9350 T1045 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 9350 T1045 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 9351 T1045 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 9352 T1045 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 9352 T1045 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 9353 T1045 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 9353 T1045 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 9354 T1045 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 9354 T1045 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 9355 T1045 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 9355 T1045 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 9356 T1045 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 9356 T1045 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 9357 T1045 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 9357 T1045 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 9358 T1045 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 9358 T1045 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 9359 T1045 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 9359 T1045 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 9360 T1045 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 9376 T1045 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 9382 T1045 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 9383 T1045 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 9386 T1045 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3
[junit4:junit4] 2> 9388 T1045 oass.SolrIndexSearcher.<init> Opening Searcher@3513b625 main
[junit4:junit4] 2> 9389 T1045 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 9389 T1045 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 9390 T1045 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 9399 T1045 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 9453 T1046 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3513b625 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 9458 T1045 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 9459 T1045 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 9538 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 9539 T996 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:11451_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:11451"}
[junit4:junit4] 2> 9539 T996 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 9539 T996 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 9562 T1001 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 9562 T1014 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 9562 T1044 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 9562 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 9562 T1029 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 10461 T1045 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 10461 T1045 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:11451 collection:collection1 shard:shard1
[junit4:junit4] 2> 10466 T1045 oasc.ZkController.register We are http://127.0.0.1:11451/collection1/ and leader is http://127.0.0.1:57687/collection1/
[junit4:junit4] 2> 10466 T1045 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:11451
[junit4:junit4] 2> 10466 T1045 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 10466 T1045 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C78 name=collection1 org.apache.solr.core.SolrCore@3b377d38 url=http://127.0.0.1:11451/collection1 node=127.0.0.1:11451_ C78_STATE=coll:collection1 core:collection1 props:{shard=null, roles=null, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:11451_, base_url=http://127.0.0.1:11451}
[junit4:junit4] 2> 10467 T1047 C78 P11451 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 10468 T1047 C78 P11451 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 10468 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 10468 T1047 C78 P11451 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 10468 T1047 C78 P11451 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 10469 T973 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 10470 T973 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 10470 T1047 C78 P11451 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 10470 T973 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 10575 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 10576 T996 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:11451_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:11451"}
[junit4:junit4] 2> 10591 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 10591 T1044 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 10591 T1001 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 10591 T1014 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 10591 T1029 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 10625 T973 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 10627 T973 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:47336
[junit4:junit4] 2> 10628 T973 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 10628 T973 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1356803403284
[junit4:junit4] 2> 10629 T973 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1356803403284/'
[junit4:junit4] 2> 10665 T973 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 10666 T973 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 10666 T973 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1356803403284
[junit4:junit4] 2> 10667 T973 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1356803403284/solr.xml
[junit4:junit4] 2> 10667 T973 oasc.CoreContainer.<init> New CoreContainer 1816198763
[junit4:junit4] 2> 10668 T973 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1356803403284/'
[junit4:junit4] 2> 10668 T973 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1356803403284/'
[junit4:junit4] 2> 10696 T973 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 30000
[junit4:junit4] 2> 10696 T973 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 10697 T973 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 10697 T973 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 10697 T973 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 10698 T973 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 10698 T973 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 10698 T973 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 10699 T973 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 10699 T973 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=30000&connTimeout=15000&retry=false
[junit4:junit4] 2> 10716 T973 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 10733 T973 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:60632/solr
[junit4:junit4] 2> 10733 T973 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 10734 T973 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60632 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@23136717
[junit4:junit4] 2> 10735 T973 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 10735 T1057 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:60632. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 10736 T1057 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:60632, initiating session
[junit4:junit4] 2> 10736 T975 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:21627
[junit4:junit4] 2> 10737 T975 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:21627
[junit4:junit4] 2> 10740 T977 oazs.ZooKeeperServer.finishSessionInit Established session 0x13be7c8c52b000b with negotiated timeout 20000 for client /140.211.11.196:21627
[junit4:junit4] 2> 10740 T1057 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:60632, sessionid = 0x13be7c8c52b000b, negotiated timeout = 20000
[junit4:junit4] 2> 10740 T1058 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@23136717 name:ZooKeeperConnection Watcher:127.0.0.1:60632 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 10740 T973 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 10741 T978 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13be7c8c52b000b
[junit4:junit4] 2> 10743 T1058 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 10743 T975 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:21627 which had sessionid 0x13be7c8c52b000b
[junit4:junit4] 2> 10742 T973 oaz.ZooKeeper.close Session: 0x13be7c8c52b000b closed
[junit4:junit4] 2> 10743 T973 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=15000&connTimeout=30000
[junit4:junit4] 2> 10751 T973 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:60632/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@29287c45
[junit4:junit4] 2> 10752 T973 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 10753 T1059 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:60632. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 10753 T1059 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:60632, initiating session
[junit4:junit4] 2> 10753 T975 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:25794
[junit4:junit4] 2> 10754 T975 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:25794
[junit4:junit4] 2> 10755 T977 oazs.ZooKeeperServer.finishSessionInit Established session 0x13be7c8c52b000c with negotiated timeout 20000 for client /140.211.11.196:25794
[junit4:junit4] 2> 10755 T1059 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:60632, sessionid = 0x13be7c8c52b000c, negotiated timeout = 20000
[junit4:junit4] 2> 10756 T1060 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29287c45 name:ZooKeeperConnection Watcher:127.0.0.1:60632/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 10756 T973 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 10757 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b000c type:create cxid:0x1 zxid:0xa6 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 10759 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b000c type:create cxid:0x2 zxid:0xa7 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 10770 T973 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47336_
[junit4:junit4] 2> 10770 T978 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13be7c8c52b000c type:delete cxid:0x4 zxid:0xa8 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:47336_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:47336_
[junit4:junit4] 2> 10771 T973 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47336_
[junit4:junit4] 2> 10778 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 10779 T1014 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 10779 T1029 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 10779 T1044 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 10779 T1001 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 10779 T1044 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 10780 T1001 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 10783 T995 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 10783 T1014 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 10783 T1029 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 10784 T973 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 10790 T1061 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1356803403284/collection1
[junit4:junit4] 2> 10790 T1061 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 10791 T1061 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 10791 T1061 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 10793 T1061 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1356803403284/collection1/'
[junit4:junit4] 2> 10794 T1061 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1356803403284/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 10795 T1061 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1356803403284/collection1/lib/README' to classloader
[junit4:junit4] 2> 10855 T1061 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4] 2> 10934 T1061 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 11035 T1061 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 11045 T1061 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 11842 T1061 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 11854 T1061 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 11859 T1061 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 11876 T1061 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 11882 T1061 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 11887 T1061 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 11888 T1061 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 11890 T1061 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1356803403284/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty4/
[junit4:junit4] 2> 11890 T1061 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e5c2ec4
[junit4:junit4] 2> 11891 T1061 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 11892 T1061 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty4 forceNew:false
[junit4:junit4] 2> 11893 T1061 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty4
[junit4:junit4] 2> 11893 T1061 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty4/index/
[junit4:junit4] 2> 11894 T1061 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 11895 T1061 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty4/index forceNew:false
[junit4:junit4] 2> 11901 T1061 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@5fd7f85d),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 11901 T1061 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 11902 T1061 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty4/index
[junit4:junit4] 2> 11903 T1061 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 11906 T1061 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 11906 T1061 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 11907 T1061 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 11908 T1061 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 11909 T1061 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 11909 T1061 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 11910 T1061 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 11910 T1061 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 11911 T1061 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 11911 T1061 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 11912 T1061 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 11913 T1061 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 11913 T1061 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 11913 T1061 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 11914 T1061 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 11914 T1061 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 11915 T1061 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 11915 T1061 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 11916 T1061 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 11917 T1061 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 11917 T1061 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 11918 T1061 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 11918 T1061 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 11919 T1061 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 11919 T1061 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 11920 T1061 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 11936 T1061 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 11942 T1061 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 11944 T1061 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 11946 T1061 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty4
[junit4:junit4] 2> 11948 T1061 oass.SolrIndexSearcher.<init> Opening Searcher@acd1e83 main
[junit4:junit4] 2> 11982 T1061 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 12000 T1061 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 12000 T1061 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 12016 T1061 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 12078 T1062 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@acd1e83 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 12086 T1061 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 12087 T1061 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 12117 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 12118 T996 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:47336_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:47336"}
[junit4:junit4] 2> 12118 T996 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 12118 T996 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 12125 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 12125 T1014 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 12125 T1001 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 12125 T1044 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 12125 T1029 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 12125 T1060 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 13090 T1061 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 13090 T1061 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:47336 collection:collection1 shard:shard2
[junit4:junit4] 2> 13095 T1061 oasc.ZkController.register We are http://127.0.0.1:47336/collection1/ and leader is http://127.0.0.1:51111/collection1/
[junit4:junit4] 2> 13095 T1061 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:47336
[junit4:junit4] 2> 13095 T1061 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 13096 T1061 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C79 name=collection1 org.apache.solr.core.SolrCore@16eb02f7 url=http://127.0.0.1:47336/collection1 node=127.0.0.1:47336_ C79_STATE=coll:collection1 core:collection1 props:{shard=null, roles=null, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:47336_, base_url=http://127.0.0.1:47336}
[junit4:junit4] 2> 13096 T1063 C79 P47336 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 13098 T1063 C79 P47336 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 13099 T1063 C79 P47336 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 13099 T1063 C79 P47336 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 13101 T1061 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13102 T1063 C79 P47336 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 13103 T973 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 13104 T973 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 13104 T973 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 13124 T973 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13126 T973 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):230
[junit4:junit4] 2> 13127 T973 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13133 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13134 T996 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:47336_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:47336"}
[junit4:junit4] 2> 13147 T1044 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 13147 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 13147 T1029 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 13147 T1014 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 13147 T1060 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 13147 T1001 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> C78_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:11451_, base_url=http://127.0.0.1:11451}
[junit4:junit4] 2> 13488 T1047 C78 P11451 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:57687/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 13488 T1047 C78 P11451 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:11451 START replicas=[http://127.0.0.1:57687/collection1/] nUpdates=100
[junit4:junit4] 2> 13489 T1047 C78 P11451 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 13489 T1047 C78 P11451 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 13489 T1047 C78 P11451 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 13489 T1047 C78 P11451 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 13489 T1047 C78 P11451 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 13490 T1047 C78 P11451 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:57687/collection1/. core=collection1
[junit4:junit4] 2> 13490 T1047 C78 P11451 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C80 name=collection1 org.apache.solr.core.SolrCore@4ce71306 url=http://127.0.0.1:57687/collection1 node=127.0.0.1:57687_ C80_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:57687_, base_url=http://127.0.0.1:57687, leader=true}
[junit4:junit4] 2> 13497 T1005 C80 P57687 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=0
[junit4:junit4] 2> 13499 T1006 C80 P57687 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4] 2> 13500 T1006 C80 P57687 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty1
[junit4:junit4] 2> 13505 T1006 C80 P57687 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@210f93dd),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 13505 T1006 C80 P57687 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 13509 T1006 C80 P57687 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@210f93dd),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@210f93dd),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 13509 T1006 C80 P57687 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 13511 T1006 C80 P57687 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty1
[junit4:junit4] 2> 13511 T1006 C80 P57687 oass.SolrIndexSearcher.<init> Opening Searcher@49dff767 realtime
[junit4:junit4] 2> 13512 T1006 C80 P57687 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 13512 T1006 C80 P57687 /update {waitSearcher=true&openSearcher=false&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 13
[junit4:junit4] 2> 13513 T1047 C78 P11451 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 13513 T1047 C78 P11451 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 13515 T1007 C80 P57687 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 13516 T1007 C80 P57687 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=2
[junit4:junit4] 2> 13516 T1047 C78 P11451 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 13517 T1047 C78 P11451 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 13517 T1047 C78 P11451 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 13519 T1007 C80 P57687 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty1
[junit4:junit4] 2> 13520 T1007 C80 P57687 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty1/index
[junit4:junit4] 2> 13520 T1007 C80 P57687 REQ /replication {command=filelist&generation=2&wt=javabin&qt=/replication&version=2} status=0 QTime=1
[junit4:junit4] 2> 13521 T1047 C78 P11451 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 13522 T1047 C78 P11451 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/index.20121229125006321 forceNew:false
[junit4:junit4] 2> 13522 T1047 C78 P11451 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3
[junit4:junit4] 2> 13523 T1047 C78 P11451 oash.SnapPuller.fetchLatestIndex Starting download to RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/index.20121229125006321 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5c43e76d) fullCopy=true
[junit4:junit4] 2> 13526 T1007 C80 P57687 REQ /replication {file=segments_2&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0
[junit4:junit4] 2> 13528 T1047 C78 P11451 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/index
[junit4:junit4] 2> 13528 T1047 C78 P11451 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 13529 T1047 C78 P11451 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20121229125006321
[junit4:junit4] 2> 13530 T1047 C78 P11451 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3
[junit4:junit4] 2> 13530 T1047 C78 P11451 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3
[junit4:junit4] 2> 13530 T1047 C78 P11451 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/index/ new=./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/index.20121229125006321
[junit4:junit4] 2> 13533 T1047 C78 P11451 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/index.20121229125006321 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5c43e76d),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 13533 T1047 C78 P11451 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 13534 T1047 C78 P11451 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3
[junit4:junit4] 2> 13535 T1047 C78 P11451 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 13535 T1047 C78 P11451 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 13535 T1047 C78 P11451 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4] 2> 13536 T1047 C78 P11451 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/index.20121229125006321
[junit4:junit4] 2> 13536 T1047 C78 P11451 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3
[junit4:junit4] 2> 13539 T1047 C78 P11451 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/index.20121229125006321 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5c43e76d),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 13539 T1047 C78 P11451 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 13539 T1047 C78 P11451 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 13540 T1047 C78 P11451 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3
[junit4:junit4] 2> 13540 T1047 C78 P11451 oass.SolrIndexSearcher.<init> Opening Searcher@55ef5991 main
[junit4:junit4] 2> 13541 T1046 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@55ef5991 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 13542 T1046 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/index
[junit4:junit4] 2> 13542 T1047 C78 P11451 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=false,waitSearcher=false,expungeDeletes=false,softCommit=false}
[junit4:junit4] 2> 13544 T1047 C78 P11451 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/index.20121229125006321 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5c43e76d),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/index.20121229125006321 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5c43e76d),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4] 2> 13544 T1047 C78 P11451 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[segments_3]
[junit4:junit4] 2> 13545 T1047 C78 P11451 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3
[junit4:junit4] 2> 13545 T1047 C78 P11451 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 13545 T1047 C78 P11451 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/index.20121229125006321
[junit4:junit4] 2> 13546 T1047 C78 P11451 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-1356803392804/jetty3/index
[junit4:junit4] 2> 13546 T1047 C78 P11451 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 13546 T1047 C78 P11451 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 13546 T1047 C78 P11451 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 13546 T1047 C78 P11451 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 13555 T1047 C78 P11451 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 13651 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13652 T996 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:11451_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:11451"}
[junit4:junit4] 2> 13665 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 13665 T1060 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 13665 T1001 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 13665 T1029 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 13665 T1014 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 13665 T1044 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 14129 T973 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 15131 T973 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> C79_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:47336_, base_url=http://127.0.0.1:47336}
[junit4:junit4] 2> 16120 T1063 C79 P47336 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:51111/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 16120 T1063 C79 P47336 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:47336 START replicas=[http://127.0.0.1:51111/collection1/] nUpdates=100
[junit4:junit4] 2> 16121 T1063 C79 P47336 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 16121 T1063 C79 P47336 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 16121 T1063 C79 P47336 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 16121 T1063 C79 P47336 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 16122 T1063 C79 P47336 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 16122 T1063 C79 P47336 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:51111/collection1/. core=collection1
[junit4:junit4] 2> 16123 T1063 C79 P4
[...truncated too long message...]
er.java:121)
[junit4:junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:575)
[junit4:junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:425)
[junit4:junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:820)
[junit4:junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:754)
[junit4:junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:732)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:352)
[junit4:junit4] > ... 5 more
[junit4:junit4] > Throwable #5: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=1537, name=testExecutor-844-thread-3, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
[junit4:junit4] > Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([4F77919082CFCB26]:0)
[junit4:junit4] > at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:642)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] > Caused by: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:413)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
[junit4:junit4] > at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:640)
[junit4:junit4] > ... 3 more
[junit4:junit4] > Caused by: org.apache.http.conn.ConnectTimeoutException: Connect to 127.0.0.1:11451 timed out
[junit4:junit4] > at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:125)
[junit4:junit4] > at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:148)
[junit4:junit4] > at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:150)
[junit4:junit4] > at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:121)
[junit4:junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:575)
[junit4:junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:425)
[junit4:junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:820)
[junit4:junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:754)
[junit4:junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:732)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:352)
[junit4:junit4] > ... 5 more
[junit4:junit4] > Throwable #6: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=1538, name=testExecutor-844-thread-4, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
[junit4:junit4] > Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([4F77919082CFCB26]:0)
[junit4:junit4] > at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:642)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] > Caused by: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:413)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
[junit4:junit4] > at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:640)
[junit4:junit4] > ... 3 more
[junit4:junit4] > Caused by: org.apache.http.conn.ConnectTimeoutException: Connect to 127.0.0.1:11451 timed out
[junit4:junit4] > at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:125)
[junit4:junit4] > at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:148)
[junit4:junit4] > at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:150)
[junit4:junit4] > at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:121)
[junit4:junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:575)
[junit4:junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:425)
[junit4:junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:820)
[junit4:junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:754)
[junit4:junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:732)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:352)
[junit4:junit4] > ... 5 more
[junit4:junit4] > Throwable #7: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=1541, name=testExecutor-844-thread-7, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
[junit4:junit4] > Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([4F77919082CFCB26]:0)
[junit4:junit4] > at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:642)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] > Caused by: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:11451
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:413)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
[junit4:junit4] > at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:640)
[junit4:junit4] > ... 3 more
[junit4:junit4] > Caused by: org.apache.http.conn.ConnectTimeoutException: Connect to 127.0.0.1:11451 timed out
[junit4:junit4] > at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:125)
[junit4:junit4] > at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:148)
[junit4:junit4] > at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:150)
[junit4:junit4] > at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:121)
[junit4:junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:575)
[junit4:junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:425)
[junit4:junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:820)
[junit4:junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:754)
[junit4:junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:732)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:352)
[junit4:junit4] > ... 5 more
[junit4:junit4] Completed on J1 in 687.72s, 1 test, 8 errors <<< FAILURES!
[...truncated 330 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/build.xml:353: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build.xml:178: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/common-build.xml:438: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/common-build.xml:1176: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/common-build.xml:841: There were test failures: 245 suites, 1013 tests, 7 suite-level errors, 1 error, 22 ignored (4 assumptions)
Total time: 51 minutes 31 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure