You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/03/10 21:23:31 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.8.0-ea-b79) - Build #
4624 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/4624/
Java: 32bit/jdk1.8.0-ea-b79 -client -XX:+UseConcMarkSweepGC
2 tests failed.
FAILED: org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch
Error Message:
Server at http://127.0.0.1:44284/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
Stack Trace:
org.apache.solr.common.SolrException: Server at http://127.0.0.1:44284/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
at __randomizedtesting.SeedInfo.seed([1DAFA987D21579E1:9C49279FA54A19DD]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:375)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:200)
at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:89)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
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:487)
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: org.apache.solr.cloud.UnloadDistributedZkTest.testDistribSearch
Error Message:
Still found shard
Stack Trace:
java.lang.AssertionError: Still found shard
at __randomizedtesting.SeedInfo.seed([1DAFA987D21579E1:9C49279FA54A19DD]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.UnloadDistributedZkTest.testUnloadShardAndCollection(UnloadDistributedZkTest.java:124)
at org.apache.solr.cloud.UnloadDistributedZkTest.doTest(UnloadDistributedZkTest.java:77)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
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:487)
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)
Build Log:
[...truncated 9380 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4] 2> 0 T1897 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 3 T1897 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362946367926
[junit4:junit4] 2> 3 T1897 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 4 T1898 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 5 T1898 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4] 2> 5 T1898 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4] 2> 5 T1898 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4] 2> 5 T1898 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> 6 T1898 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4] 2> 104 T1897 oasc.ZkTestServer.run start zk server on port:47139
[junit4:junit4] 2> 104 T1897 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47139 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@7405aa
[junit4:junit4] 2> 105 T1903 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47139. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 105 T1897 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 105 T1903 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47139, initiating session
[junit4:junit4] 2> 106 T1899 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:47623
[junit4:junit4] 2> 106 T1899 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:47623
[junit4:junit4] 2> 106 T1901 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4] 2> 187 T1901 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d55ef21b90000 with negotiated timeout 10000 for client /127.0.0.1:47623
[junit4:junit4] 2> 187 T1903 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47139, sessionid = 0x13d55ef21b90000, negotiated timeout = 10000
[junit4:junit4] 2> 187 T1904 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7405aa name:ZooKeeperConnection Watcher:127.0.0.1:47139 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 187 T1897 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 188 T1897 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 192 T1902 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d55ef21b90000
[junit4:junit4] 2> 193 T1904 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 194 T1899 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:47623 which had sessionid 0x13d55ef21b90000
[junit4:junit4] 2> 193 T1897 oaz.ZooKeeper.close Session: 0x13d55ef21b90000 closed
[junit4:junit4] 2> 195 T1897 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47139/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@b3e794
[junit4:junit4] 2> 196 T1905 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47139. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 196 T1897 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 197 T1905 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47139, initiating session
[junit4:junit4] 2> 197 T1899 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:47624
[junit4:junit4] 2> 198 T1899 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:47624
[junit4:junit4] 2> 199 T1901 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d55ef21b90001 with negotiated timeout 10000 for client /127.0.0.1:47624
[junit4:junit4] 2> 199 T1905 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47139, sessionid = 0x13d55ef21b90001, negotiated timeout = 10000
[junit4:junit4] 2> 200 T1906 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b3e794 name:ZooKeeperConnection Watcher:127.0.0.1:47139/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 200 T1897 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 201 T1897 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 205 T1897 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 208 T1897 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 211 T1897 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 214 T1897 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 215 T1897 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 220 T1897 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 221 T1897 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 226 T1897 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 227 T1897 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 230 T1897 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 231 T1897 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 234 T1897 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 235 T1897 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 239 T1897 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 239 T1897 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 243 T1897 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 243 T1897 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 247 T1897 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 248 T1897 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 251 T1897 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 252 T1897 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 255 T1902 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d55ef21b90001
[junit4:junit4] 2> 256 T1899 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:47624 which had sessionid 0x13d55ef21b90001
[junit4:junit4] 2> 256 T1906 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 256 T1897 oaz.ZooKeeper.close Session: 0x13d55ef21b90001 closed
[junit4:junit4] 2> 327 T1897 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 330 T1897 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:48486
[junit4:junit4] 2> 331 T1897 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 331 T1897 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 331 T1897 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362946368181
[junit4:junit4] 2> 332 T1897 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362946368181/solr.xml
[junit4:junit4] 2> 332 T1897 oasc.CoreContainer.<init> New CoreContainer 30627161
[junit4:junit4] 2> 332 T1897 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362946368181/'
[junit4:junit4] 2> 333 T1897 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362946368181/'
[junit4:junit4] 2> 351 T1897 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 351 T1897 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 352 T1897 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 352 T1897 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 352 T1897 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 353 T1897 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 353 T1897 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 353 T1897 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 354 T1897 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 354 T1897 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 361 T1897 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 372 T1897 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:47139/solr
[junit4:junit4] 2> 373 T1897 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 373 T1897 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47139 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@ba550d
[junit4:junit4] 2> 374 T1897 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 374 T1916 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47139. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 375 T1916 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47139, initiating session
[junit4:junit4] 2> 375 T1899 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:47625
[junit4:junit4] 2> 375 T1899 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:47625
[junit4:junit4] 2> 376 T1901 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d55ef21b90002 with negotiated timeout 20000 for client /127.0.0.1:47625
[junit4:junit4] 2> 376 T1916 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47139, sessionid = 0x13d55ef21b90002, negotiated timeout = 20000
[junit4:junit4] 2> 377 T1917 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ba550d name:ZooKeeperConnection Watcher:127.0.0.1:47139 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 377 T1897 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 380 T1902 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d55ef21b90002
[junit4:junit4] 2> 381 T1917 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 381 T1899 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:47625 which had sessionid 0x13d55ef21b90002
[junit4:junit4] 2> 381 T1897 oaz.ZooKeeper.close Session: 0x13d55ef21b90002 closed
[junit4:junit4] 2> 382 T1897 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 384 T1897 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47139/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1d70dfe
[junit4:junit4] 2> 385 T1918 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47139. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 385 T1897 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 386 T1918 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47139, initiating session
[junit4:junit4] 2> 386 T1899 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:47626
[junit4:junit4] 2> 386 T1899 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:47626
[junit4:junit4] 2> 387 T1901 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d55ef21b90003 with negotiated timeout 20000 for client /127.0.0.1:47626
[junit4:junit4] 2> 388 T1918 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47139, sessionid = 0x13d55ef21b90003, negotiated timeout = 20000
[junit4:junit4] 2> 388 T1919 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d70dfe name:ZooKeeperConnection Watcher:127.0.0.1:47139/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 389 T1897 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 391 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 393 T1897 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 395 T1897 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48486_
[junit4:junit4] 2> 396 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:48486_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:48486_
[junit4:junit4] 2> 397 T1897 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48486_
[junit4:junit4] 2> 400 T1897 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 406 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90003 type:delete cxid:0x16 zxid:0x21 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4] 2> 407 T1897 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 410 T1897 oasc.Overseer.start Overseer (id=89322053168594947-127.0.0.1:48486_-n_0000000000) starting
[junit4:junit4] 2> 412 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 413 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 414 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 415 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 416 T1921 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 417 T1897 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 429 T1897 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 432 T1897 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 435 T1920 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 440 T1922 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362946368181/collection1
[junit4:junit4] 2> 440 T1922 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 441 T1922 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 442 T1922 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 443 T1922 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362946368181/collection1/'
[junit4:junit4] 2> 444 T1922 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362946368181/collection1/lib/README' to classloader
[junit4:junit4] 2> 445 T1922 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362946368181/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 486 T1922 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 523 T1922 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 524 T1922 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 529 T1922 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 963 T1922 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 970 T1922 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 973 T1922 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 981 T1922 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 985 T1922 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 988 T1922 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 988 T1922 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 989 T1922 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 989 T1922 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 990 T1922 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 990 T1922 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 990 T1922 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362946368181/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/control/data/
[junit4:junit4] 2> 991 T1922 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cdc556
[junit4:junit4] 2> 991 T1922 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 991 T1922 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/control/data forceNew: false
[junit4:junit4] 2> 992 T1922 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/control/data/index/
[junit4:junit4] 2> 992 T1922 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 992 T1922 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/control/data/index forceNew: false
[junit4:junit4] 2> 994 T1922 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b748fd lockFactory=org.apache.lucene.store.NativeFSLockFactory@1298328),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 994 T1922 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 995 T1922 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 995 T1922 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 996 T1922 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 996 T1922 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 997 T1922 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 997 T1922 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 997 T1922 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 998 T1922 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 998 T1922 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1000 T1922 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1003 T1922 oass.SolrIndexSearcher.<init> Opening Searcher@1ea02a0 main
[junit4:junit4] 2> 1003 T1922 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/control/data/tlog
[junit4:junit4] 2> 1004 T1922 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1004 T1922 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1007 T1923 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1ea02a0 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1012 T1922 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1012 T1922 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1012 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90003 type:create cxid:0x55 zxid:0x2a txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4] 2> 1939 T1920 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1939 T1920 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "base_url":"http://127.0.0.1:48486",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:48486_"}
[junit4:junit4] 2> 1940 T1920 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 1940 T1920 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 1941 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90003 type:create cxid:0x5d zxid:0x2d txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4] 2> 1946 T1919 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> 2014 T1922 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2014 T1922 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48486 collection:control_collection shard:shard1
[junit4:junit4] 2> 2015 T1922 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2023 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90003 type:delete cxid:0x77 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4] 2> 2024 T1922 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2025 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90003 type:create cxid:0x78 zxid:0x38 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 2027 T1922 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2027 T1922 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2028 T1922 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:48486/collection1/
[junit4:junit4] 2> 2028 T1922 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2029 T1922 oasc.SyncStrategy.syncToMe http://127.0.0.1:48486/collection1/ has no replicas
[junit4:junit4] 2> 2029 T1922 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:48486/collection1/
[junit4:junit4] 2> 2029 T1922 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 2034 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90003 type:create cxid:0x82 zxid:0x3c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3451 T1920 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3465 T1919 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> 3490 T1922 oasc.ZkController.register We are http://127.0.0.1:48486/collection1/ and leader is http://127.0.0.1:48486/collection1/
[junit4:junit4] 2> 3490 T1922 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48486
[junit4:junit4] 2> 3491 T1922 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 3491 T1922 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 3491 T1922 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 3494 T1922 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3495 T1897 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 3496 T1897 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 3497 T1897 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 3503 T1897 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 3504 T1897 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47139/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@114bec8
[junit4:junit4] 2> 3506 T1897 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3506 T1925 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47139. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3507 T1925 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47139, initiating session
[junit4:junit4] 2> 3507 T1899 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:47636
[junit4:junit4] 2> 3507 T1899 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:47636
[junit4:junit4] 2> 3508 T1901 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d55ef21b90004 with negotiated timeout 10000 for client /127.0.0.1:47636
[junit4:junit4] 2> 3509 T1925 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47139, sessionid = 0x13d55ef21b90004, negotiated timeout = 10000
[junit4:junit4] 2> 3509 T1926 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@114bec8 name:ZooKeeperConnection Watcher:127.0.0.1:47139/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3510 T1897 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3513 T1897 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 3515 T1897 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 3587 T1897 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 3590 T1897 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44842
[junit4:junit4] 2> 3590 T1897 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 3591 T1897 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 3591 T1897 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362946371439
[junit4:junit4] 2> 3592 T1897 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362946371439/solr.xml
[junit4:junit4] 2> 3592 T1897 oasc.CoreContainer.<init> New CoreContainer 6986405
[junit4:junit4] 2> 3593 T1897 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362946371439/'
[junit4:junit4] 2> 3593 T1897 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362946371439/'
[junit4:junit4] 2> 3617 T1897 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 3617 T1897 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 3618 T1897 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 3618 T1897 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 3619 T1897 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 3619 T1897 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 3620 T1897 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 3620 T1897 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 3621 T1897 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 3621 T1897 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 3630 T1897 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 3645 T1897 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:47139/solr
[junit4:junit4] 2> 3645 T1897 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 3646 T1897 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47139 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@13be804
[junit4:junit4] 2> 3647 T1936 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47139. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3647 T1897 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3648 T1936 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47139, initiating session
[junit4:junit4] 2> 3648 T1899 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:47639
[junit4:junit4] 2> 3648 T1899 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:47639
[junit4:junit4] 2> 3650 T1901 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d55ef21b90005 with negotiated timeout 20000 for client /127.0.0.1:47639
[junit4:junit4] 2> 3650 T1936 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47139, sessionid = 0x13d55ef21b90005, negotiated timeout = 20000
[junit4:junit4] 2> 3650 T1937 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13be804 name:ZooKeeperConnection Watcher:127.0.0.1:47139 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3651 T1897 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3652 T1902 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d55ef21b90005
[junit4:junit4] 2> 3653 T1937 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 3653 T1899 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:47639 which had sessionid 0x13d55ef21b90005
[junit4:junit4] 2> 3653 T1897 oaz.ZooKeeper.close Session: 0x13d55ef21b90005 closed
[junit4:junit4] 2> 3654 T1897 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 3657 T1897 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47139/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@186734b
[junit4:junit4] 2> 3658 T1938 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47139. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3658 T1897 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3659 T1938 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47139, initiating session
[junit4:junit4] 2> 3659 T1899 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:47640
[junit4:junit4] 2> 3659 T1899 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:47640
[junit4:junit4] 2> 3661 T1901 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d55ef21b90006 with negotiated timeout 20000 for client /127.0.0.1:47640
[junit4:junit4] 2> 3661 T1938 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47139, sessionid = 0x13d55ef21b90006, negotiated timeout = 20000
[junit4:junit4] 2> 3661 T1939 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@186734b name:ZooKeeperConnection Watcher:127.0.0.1:47139/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3662 T1897 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3663 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90006 type:create cxid:0x1 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3664 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90006 type:create cxid:0x2 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3666 T1897 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 4669 T1897 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44842_
[junit4:junit4] 2> 4671 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90006 type:delete cxid:0xb zxid:0x4c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:44842_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:44842_
[junit4:junit4] 2> 4672 T1897 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44842_
[junit4:junit4] 2> 4675 T1919 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> 4676 T1926 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4676 T1939 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4678 T1919 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4686 T1940 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362946371439/collection1
[junit4:junit4] 2> 4687 T1940 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 4688 T1940 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 4688 T1940 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 4689 T1940 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362946371439/collection1/'
[junit4:junit4] 2> 4690 T1940 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362946371439/collection1/lib/README' to classloader
[junit4:junit4] 2> 4690 T1940 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362946371439/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 4730 T1940 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 4785 T1940 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 4786 T1940 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 4793 T1940 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 4970 T1920 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 4971 T1920 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "base_url":"http://127.0.0.1:48486",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:48486_"}
[junit4:junit4] 2> 4973 T1939 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> 4973 T1926 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> 4973 T1919 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> 5215 T1940 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 5223 T1940 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 5227 T1940 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 5235 T1940 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 5238 T1940 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 5241 T1940 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 5242 T1940 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 5243 T1940 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 5243 T1940 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 5244 T1940 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 5244 T1940 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 5244 T1940 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362946371439/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty1/
[junit4:junit4] 2> 5244 T1940 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cdc556
[junit4:junit4] 2> 5245 T1940 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 5245 T1940 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty1 forceNew: false
[junit4:junit4] 2> 5246 T1940 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty1/index/
[junit4:junit4] 2> 5246 T1940 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 5246 T1940 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty1/index forceNew: false
[junit4:junit4] 2> 5247 T1940 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@143de8a lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c86f77),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 5247 T1940 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 5249 T1940 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 5249 T1940 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 5250 T1940 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 5251 T1940 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 5251 T1940 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 5251 T1940 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 5252 T1940 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 5252 T1940 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 5253 T1940 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 5256 T1940 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 5260 T1940 oass.SolrIndexSearcher.<init> Opening Searcher@9c02d main
[junit4:junit4] 2> 5260 T1940 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty1/tlog
[junit4:junit4] 2> 5261 T1940 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 5261 T1940 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 5267 T1941 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9c02d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 5269 T1940 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 5270 T1940 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 6476 T1920 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 6477 T1920 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44842",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:44842_"}
[junit4:junit4] 2> 6477 T1920 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 6477 T1920 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 6508 T1919 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> 6508 T1939 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> 6508 T1926 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> 7272 T1940 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 7272 T1940 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:44842 collection:collection1 shard:shard2
[junit4:junit4] 2> 7273 T1940 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 7277 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90006 type:delete cxid:0x48 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4] 2> 7278 T1940 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 7279 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90006 type:create cxid:0x49 zxid:0x5d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 7280 T1940 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 7281 T1940 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 7281 T1940 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:44842/collection1/
[junit4:junit4] 2> 7281 T1940 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 7282 T1940 oasc.SyncStrategy.syncToMe http://127.0.0.1:44842/collection1/ has no replicas
[junit4:junit4] 2> 7282 T1940 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:44842/collection1/
[junit4:junit4] 2> 7282 T1940 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 7285 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90006 type:create cxid:0x53 zxid:0x61 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8013 T1920 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8023 T1919 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> 8023 T1926 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> 8023 T1939 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> 8037 T1940 oasc.ZkController.register We are http://127.0.0.1:44842/collection1/ and leader is http://127.0.0.1:44842/collection1/
[junit4:junit4] 2> 8038 T1940 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44842
[junit4:junit4] 2> 8038 T1940 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 8039 T1940 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 8039 T1940 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 8041 T1940 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8042 T1897 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 8043 T1897 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 8044 T1897 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 8111 T1897 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 8113 T1897 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44284
[junit4:junit4] 2> 8113 T1897 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 8114 T1897 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 8114 T1897 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362946375972
[junit4:junit4] 2> 8114 T1897 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362946375972/solr.xml
[junit4:junit4] 2> 8115 T1897 oasc.CoreContainer.<init> New CoreContainer 3699409
[junit4:junit4] 2> 8115 T1897 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362946375972/'
[junit4:junit4] 2> 8116 T1897 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362946375972/'
[junit4:junit4] 2> 8135 T1897 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 8136 T1897 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 8136 T1897 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 8137 T1897 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 8137 T1897 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 8138 T1897 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 8138 T1897 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 8139 T1897 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 8139 T1897 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 8140 T1897 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 8147 T1897 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 8167 T1897 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:47139/solr
[junit4:junit4] 2> 8168 T1897 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 8168 T1897 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47139 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@11b3cea
[junit4:junit4] 2> 8169 T1897 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8169 T1952 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47139. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 8170 T1952 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47139, initiating session
[junit4:junit4] 2> 8170 T1899 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:47645
[junit4:junit4] 2> 8171 T1899 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:47645
[junit4:junit4] 2> 8172 T1901 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d55ef21b90007 with negotiated timeout 20000 for client /127.0.0.1:47645
[junit4:junit4] 2> 8172 T1952 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47139, sessionid = 0x13d55ef21b90007, negotiated timeout = 20000
[junit4:junit4] 2> 8172 T1953 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11b3cea name:ZooKeeperConnection Watcher:127.0.0.1:47139 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8173 T1897 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8174 T1902 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d55ef21b90007
[junit4:junit4] 2> 8175 T1953 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 8175 T1899 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:47645 which had sessionid 0x13d55ef21b90007
[junit4:junit4] 2> 8175 T1897 oaz.ZooKeeper.close Session: 0x13d55ef21b90007 closed
[junit4:junit4] 2> 8176 T1897 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 8179 T1897 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47139/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@74a5f4
[junit4:junit4] 2> 8180 T1954 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47139. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 8180 T1897 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8181 T1954 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47139, initiating session
[junit4:junit4] 2> 8181 T1899 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:47646
[junit4:junit4] 2> 8181 T1899 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:47646
[junit4:junit4] 2> 8182 T1901 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d55ef21b90008 with negotiated timeout 20000 for client /127.0.0.1:47646
[junit4:junit4] 2> 8183 T1954 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47139, sessionid = 0x13d55ef21b90008, negotiated timeout = 20000
[junit4:junit4] 2> 8183 T1955 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@74a5f4 name:ZooKeeperConnection Watcher:127.0.0.1:47139/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8184 T1897 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8185 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90008 type:create cxid:0x1 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8186 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90008 type:create cxid:0x2 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8188 T1897 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 9192 T1897 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44284_
[junit4:junit4] 2> 9193 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90008 type:delete cxid:0xb zxid:0x70 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:44284_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:44284_
[junit4:junit4] 2> 9194 T1897 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44284_
[junit4:junit4] 2> 9195 T1919 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> 9195 T1939 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> 9195 T1926 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> 9196 T1955 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9197 T1919 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9198 T1926 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9198 T1939 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9202 T1956 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362946375972/collection1
[junit4:junit4] 2> 9202 T1956 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 9203 T1956 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 9203 T1956 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 9204 T1956 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362946375972/collection1/'
[junit4:junit4] 2> 9204 T1956 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362946375972/collection1/lib/README' to classloader
[junit4:junit4] 2> 9204 T1956 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362946375972/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 9239 T1956 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 9279 T1956 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 9280 T1956 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 9285 T1956 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 9532 T1920 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 9532 T1920 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44842",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:44842_"}
[junit4:junit4] 2> 9535 T1955 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> 9535 T1926 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> 9535 T1939 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> 9535 T1919 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> 9728 T1956 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 9734 T1956 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 9737 T1956 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 9746 T1956 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 9750 T1956 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 9753 T1956 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 9754 T1956 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 9755 T1956 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 9755 T1956 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 9756 T1956 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 9756 T1956 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 9756 T1956 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362946375972/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty2/
[junit4:junit4] 2> 9756 T1956 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cdc556
[junit4:junit4] 2> 9757 T1956 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 9758 T1956 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty2 forceNew: false
[junit4:junit4] 2> 9758 T1956 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty2/index/
[junit4:junit4] 2> 9758 T1956 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 9758 T1956 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty2/index forceNew: false
[junit4:junit4] 2> 9765 T1956 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f93259 lockFactory=org.apache.lucene.store.NativeFSLockFactory@10588b0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 9765 T1956 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 9767 T1956 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 9768 T1956 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 9768 T1956 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 9769 T1956 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 9769 T1956 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 9770 T1956 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 9770 T1956 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 9770 T1956 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 9771 T1956 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 9773 T1956 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 9776 T1956 oass.SolrIndexSearcher.<init> Opening Searcher@135fd7a main
[junit4:junit4] 2> 9777 T1956 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty2/tlog
[junit4:junit4] 2> 9777 T1956 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 9778 T1956 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 9782 T1957 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@135fd7a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 9785 T1956 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 9785 T1956 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 11040 T1920 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 11040 T1920 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44284",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:44284_"}
[junit4:junit4] 2> 11041 T1920 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 11041 T1920 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 11046 T1955 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> 11046 T1919 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> 11046 T1926 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> 11046 T1939 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> 11786 T1956 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 11787 T1956 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:44284 collection:collection1 shard:shard1
[junit4:junit4] 2> 11788 T1956 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 11796 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90008 type:delete cxid:0x47 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard1 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard1
[junit4:junit4] 2> 11797 T1956 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 11798 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90008 type:create cxid:0x48 zxid:0x80 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 11800 T1956 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 11801 T1956 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 11801 T1956 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:44284/collection1/
[junit4:junit4] 2> 11802 T1956 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 11802 T1956 oasc.SyncStrategy.syncToMe http://127.0.0.1:44284/collection1/ has no replicas
[junit4:junit4] 2> 11802 T1956 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:44284/collection1/
[junit4:junit4] 2> 11803 T1956 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 11808 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90008 type:create cxid:0x51 zxid:0x83 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 12551 T1920 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 12556 T1919 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> 12556 T1926 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> 12556 T1955 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> 12556 T1939 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> 12562 T1956 oasc.ZkController.register We are http://127.0.0.1:44284/collection1/ and leader is http://127.0.0.1:44284/collection1/
[junit4:junit4] 2> 12562 T1956 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44284
[junit4:junit4] 2> 12563 T1956 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 12563 T1956 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 12563 T1956 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 12565 T1956 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 12566 T1897 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 12567 T1897 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 12568 T1897 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 12651 T1897 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 12653 T1897 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58142
[junit4:junit4] 2> 12653 T1897 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 12654 T1897 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 12654 T1897 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362946380495
[junit4:junit4] 2> 12655 T1897 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362946380495/solr.xml
[junit4:junit4] 2> 12655 T1897 oasc.CoreContainer.<init> New CoreContainer 18773593
[junit4:junit4] 2> 12656 T1897 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362946380495/'
[junit4:junit4] 2> 12656 T1897 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362946380495/'
[junit4:junit4] 2> 12682 T1897 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 12683 T1897 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 12683 T1897 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 12684 T1897 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 12684 T1897 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 12684 T1897 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 12685 T1897 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 12685 T1897 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 12686 T1897 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 12686 T1897 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 12695 T1897 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 12709 T1897 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:47139/solr
[junit4:junit4] 2> 12710 T1897 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 12710 T1897 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47139 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@89a9d3
[junit4:junit4] 2> 12711 T1897 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 12711 T1968 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47139. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 12712 T1968 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47139, initiating session
[junit4:junit4] 2> 12712 T1899 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:47649
[junit4:junit4] 2> 12713 T1899 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:47649
[junit4:junit4] 2> 12714 T1901 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d55ef21b90009 with negotiated timeout 20000 for client /127.0.0.1:47649
[junit4:junit4] 2> 12714 T1968 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47139, sessionid = 0x13d55ef21b90009, negotiated timeout = 20000
[junit4:junit4] 2> 12714 T1969 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@89a9d3 name:ZooKeeperConnection Watcher:127.0.0.1:47139 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 12714 T1897 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 12715 T1902 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d55ef21b90009
[junit4:junit4] 2> 12716 T1969 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 12716 T1899 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:47649 which had sessionid 0x13d55ef21b90009
[junit4:junit4] 2> 12716 T1897 oaz.ZooKeeper.close Session: 0x13d55ef21b90009 closed
[junit4:junit4] 2> 12717 T1897 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 12720 T1897 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47139/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1c8e16b
[junit4:junit4] 2> 12721 T1897 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 12721 T1970 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47139. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 12722 T1970 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47139, initiating session
[junit4:junit4] 2> 12722 T1899 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:47650
[junit4:junit4] 2> 12722 T1899 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:47650
[junit4:junit4] 2> 12723 T1901 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d55ef21b9000a with negotiated timeout 20000 for client /127.0.0.1:47650
[junit4:junit4] 2> 12723 T1970 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47139, sessionid = 0x13d55ef21b9000a, negotiated timeout = 20000
[junit4:junit4] 2> 12723 T1971 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c8e16b name:ZooKeeperConnection Watcher:127.0.0.1:47139/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 12724 T1897 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 12725 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b9000a type:create cxid:0x1 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 12726 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b9000a type:create cxid:0x2 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 12727 T1897 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 13729 T1897 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58142_
[junit4:junit4] 2> 13730 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b9000a type:delete cxid:0xb zxid:0x92 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:58142_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:58142_
[junit4:junit4] 2> 13731 T1897 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58142_
[junit4:junit4] 2> 13733 T1919 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> 13733 T1939 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13734 T1955 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13734 T1971 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13734 T1939 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> 13734 T1955 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> 13735 T1919 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13736 T1926 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13736 T1926 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> 13741 T1972 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362946380495/collection1
[junit4:junit4] 2> 13742 T1972 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 13742 T1972 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 13743 T1972 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 13746 T1972 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362946380495/collection1/'
[junit4:junit4] 2> 13746 T1972 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362946380495/collection1/lib/README' to classloader
[junit4:junit4] 2> 13746 T1972 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362946380495/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 13781 T1972 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 13829 T1972 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 13830 T1972 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 13836 T1972 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 14062 T1920 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 14062 T1920 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44284",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:44284_"}
[junit4:junit4] 2> 14067 T1955 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> 14067 T1971 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> 14067 T1919 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> 14067 T1926 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> 14067 T1939 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> 14276 T1972 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 14283 T1972 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 14287 T1972 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 14298 T1972 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 14301 T1972 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 14304 T1972 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 14305 T1972 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 14306 T1972 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 14306 T1972 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 14307 T1972 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 14307 T1972 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 14308 T1972 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362946380495/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty3/
[junit4:junit4] 2> 14308 T1972 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cdc556
[junit4:junit4] 2> 14309 T1972 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 14309 T1972 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty3 forceNew: false
[junit4:junit4] 2> 14309 T1972 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty3/index/
[junit4:junit4] 2> 14310 T1972 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 14310 T1972 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty3/index forceNew: false
[junit4:junit4] 2> 14312 T1972 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2293bc lockFactory=org.apache.lucene.store.NativeFSLockFactory@54d7ae),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 14312 T1972 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 14314 T1972 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 14314 T1972 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 14314 T1972 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 14315 T1972 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 14315 T1972 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 14315 T1972 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 14316 T1972 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 14316 T1972 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 14317 T1972 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 14320 T1972 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 14323 T1972 oass.SolrIndexSearcher.<init> Opening Searcher@17daa3e main
[junit4:junit4] 2> 14323 T1972 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty3/tlog
[junit4:junit4] 2> 14324 T1972 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 14324 T1972 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 14328 T1973 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@17daa3e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 14331 T1972 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 14331 T1972 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 15573 T1920 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 15574 T1920 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58142",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:58142_"}
[junit4:junit4] 2> 15575 T1920 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 15576 T1920 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 15582 T1971 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> 15582 T1919 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> 15582 T1926 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> 15583 T1955 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> 15582 T1939 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> 16332 T1972 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 16332 T1972 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58142 collection:collection1 shard:shard2
[junit4:junit4] 2> 16335 T1972 oasc.ZkController.register We are http://127.0.0.1:58142/collection1/ and leader is http://127.0.0.1:44842/collection1/
[junit4:junit4] 2> 16336 T1972 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58142
[junit4:junit4] 2> 16336 T1972 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 16336 T1972 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C87 name=collection1 org.apache.solr.core.SolrCore@1b8dd26 url=http://127.0.0.1:58142/collection1 node=127.0.0.1:58142_ C87_STATE=coll:collection1 core:collection1 props:{state=down, collection=collection1, base_url=http://127.0.0.1:58142, core=collection1, node_name=127.0.0.1:58142_}
[junit4:junit4] 2> 16337 T1974 C87 P58142 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 16337 T1972 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 16338 T1974 C87 P58142 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 16338 T1974 C87 P58142 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 16338 T1974 C87 P58142 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 16339 T1897 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 16339 T1974 C87 P58142 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 16339 T1897 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 16340 T1897 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 16344 T1897 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 16346 T1897 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 16351 T1934 oasc.CoreContainer.create Creating SolrCore 'onenodecollectioncore' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362946371439/onenodecollectioncore
[junit4:junit4] 2> 16352 T1934 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4] 2> 16352 T1934 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4] 2> 16353 T1934 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 16353 T1934 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 16354 T1934 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4] 2> 16355 T1934 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4] 2> 16356 T1934 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362946371439/onenodecollectioncore/'
[junit4:junit4] 2> 16393 T1934 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 16444 T1934 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 16445 T1934 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 16452 T1934 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 16902 T1934 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 16908 T1934 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 16911 T1934 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 16920 T1934 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 16923 T1934 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 16926 T1934 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 16927 T1934 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 16928 T1934 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 16928 T1934 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 16929 T1934 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 16929 T1934 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 16930 T1934 oasc.SolrCore.<init> [onenodecollectioncore] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362946371439/onenodecollectioncore/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362946367926/onenodecollection/
[junit4:junit4] 2> 16930 T1934 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cdc556
[junit4:junit4] 2> 16930 T1934 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 16931 T1934 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362946367926/onenodecollection forceNew: false
[junit4:junit4] 2> 16931 T1934 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362946367926/onenodecollection/index/
[junit4:junit4] 2> 16932 T1934 oasc.SolrCore.initIndex WARNING [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362946367926/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 16932 T1934 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362946367926/onenodecollection/index forceNew: false
[junit4:junit4] 2> 16933 T1934 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1ed863c lockFactory=org.apache.lucene.store.NativeFSLockFactory@1e11553),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 16934 T1934 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 16936 T1934 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 16936 T1934 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 16937 T1934 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 16937 T1934 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 16938 T1934 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 16938 T1934 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 16938 T1934 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 16939 T1934 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 16939 T1934 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 16942 T1934 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 16945 T1934 oass.SolrIndexSearcher.<init> Opening Searcher@687a74 main
[junit4:junit4] 2> 16945 T1934 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362946367926/onenodecollection/tlog
[junit4:junit4] 2> 16946 T1934 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 16946 T1934 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 16949 T1976 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@687a74 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 16950 T1934 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> 17088 T1920 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 17089 T1920 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58142",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:58142_"}
[junit4:junit4] 2> 17093 T1920 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44842",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:44842_"}
[junit4:junit4] 2> 17094 T1920 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4] 2> 17094 T1920 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 17099 T1955 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> 17099 T1919 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> 17099 T1939 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> 17099 T1971 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> 17099 T1926 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> 17345 T1933 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {state=recovering&coreNodeName=127.0.0.1:58142__collection1&action=PREPRECOVERY&wt=javabin&nodeName=127.0.0.1:58142_&checkLive=true&onlyIfLeader=true&core=collection1&version=2} status=0 QTime=1000
[junit4:junit4] 2> 17951 T1934 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4] 2> 17952 T1934 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:44842 collection:onenodecollection shard:shard1
[junit4:junit4] 2> 17954 T1934 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4] 2> 17965 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90006 type:delete cxid:0xa1 zxid:0xad txntype:-1 reqpath:n/a Error Path:/solr/collections/onenodecollection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/onenodecollection/leaders
[junit4:junit4] 2> 17966 T1934 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 17967 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90006 type:create cxid:0xa2 zxid:0xae txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 17969 T1934 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 17970 T1934 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 17971 T1934 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:44842/onenodecollectioncore/
[junit4:junit4] 2> 17971 T1934 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 17972 T1934 oasc.SyncStrategy.syncToMe http://127.0.0.1:44842/onenodecollectioncore/ has no replicas
[junit4:junit4] 2> 17972 T1934 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:44842/onenodecollectioncore/
[junit4:junit4] 2> 17973 T1934 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4] 2> 17978 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90006 type:create cxid:0xac zxid:0xb2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 18607 T1920 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 18614 T1919 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> 18614 T1971 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> 18614 T1939 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> 18615 T1926 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> 18614 T1955 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> 18632 T1934 oasc.ZkController.register We are http://127.0.0.1:44842/onenodecollectioncore/ and leader is http://127.0.0.1:44842/onenodecollectioncore/
[junit4:junit4] 2> 18633 T1934 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:44842
[junit4:junit4] 2> 18633 T1934 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 18634 T1934 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4] 2> 18637 T1934 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 18638 T1934 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {roles=none&collection=onenodecollection&name=onenodecollectioncore&action=CREATE&wt=javabin&dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362946367926/onenodecollection&numShards=1&version=2} status=0 QTime=2287
[junit4:junit4] 2> 18639 T1897 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4] 2> 18640 T1897 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> C87_STATE=coll:collection1 core:collection1 props:{state=recovering, shard=shard2, collection=collection1, base_url=http://127.0.0.1:58142, core=collection1, node_name=127.0.0.1:58142_}
[junit4:junit4] 2> 19346 T1974 C87 P58142 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:44842/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 19347 T1974 C87 P58142 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:58142 START replicas=[http://127.0.0.1:44842/collection1/] nUpdates=100
[junit4:junit4] 2> 19348 T1974 C87 P58142 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 19348 T1974 C87 P58142 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 19349 T1974 C87 P58142 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 19349 T1974 C87 P58142 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 19349 T1974 C87 P58142 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 19350 T1974 C87 P58142 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:44842/collection1/. core=collection1
[junit4:junit4] 2> 19350 T1974 C87 P58142 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C88 name=collection1 org.apache.solr.core.SolrCore@9080bd url=http://127.0.0.1:44842/collection1 node=127.0.0.1:44842_ C88_STATE=coll:collection1 core:collection1 props:{state=active, shard=shard2, collection=collection1, base_url=http://127.0.0.1:44842, core=collection1, node_name=127.0.0.1:44842_, leader=true}
[junit4:junit4] 2> 19358 T1935 C88 P44842 REQ /get {distrib=false&wt=javabin&qt=/get&getVersions=100&version=2} status=0 QTime=0
[junit4:junit4] 2> 19360 T1933 C88 P44842 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 19362 T1933 C88 P44842 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@143de8a lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c86f77),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 19363 T1933 C88 P44842 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 19364 T1933 C88 P44842 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@143de8a lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c86f77),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@143de8a lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c86f77),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 19365 T1933 C88 P44842 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 19366 T1933 C88 P44842 oass.SolrIndexSearcher.<init> Opening Searcher@1cd1c47 realtime
[junit4:junit4] 2> 19366 T1933 C88 P44842 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 19367 T1933 C88 P44842 /update {softCommit=false&commit=true&openSearcher=false&waitSearcher=true&wt=javabin&commit_end_point=true&version=2} {commit=} 0 7
[junit4:junit4] 2> 19368 T1974 C87 P58142 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 19368 T1974 C87 P58142 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 19375 T1934 C88 P44842 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 19376 T1934 C88 P44842 REQ /replication {wt=javabin&command=indexversion&qt=/replication&version=2} status=0 QTime=6
[junit4:junit4] 2> 19377 T1974 C87 P58142 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 19377 T1974 C87 P58142 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 19377 T1974 C87 P58142 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 19380 T1935 C88 P44842 REQ /replication {generation=2&wt=javabin&command=filelist&qt=/replication&version=2} status=0 QTime=1
[junit4:junit4] 2> 19380 T1974 C87 P58142 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 19382 T1974 C87 P58142 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty3/index.20130310161307304 forceNew: false
[junit4:junit4] 2> 19383 T1974 C87 P58142 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c4b765 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1ea4705) fullCopy=false
[junit4:junit4] 2> 19386 T1933 C88 P44842 REQ /replication {generation=2&wt=filestream&file=segments_2&command=filecontent&checksum=true&qt=/replication} status=0 QTime=0
[junit4:junit4] 2> 19388 T1974 C87 P58142 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 19389 T1974 C87 P58142 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 19389 T1974 C87 P58142 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 19391 T1974 C87 P58142 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2293bc lockFactory=org.apache.lucene.store.NativeFSLockFactory@54d7ae),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2293bc lockFactory=org.apache.lucene.store.NativeFSLockFactory@54d7ae),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 19392 T1974 C87 P58142 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 19393 T1974 C87 P58142 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 19394 T1974 C87 P58142 oass.SolrIndexSearcher.<init> Opening Searcher@1860d6d main
[junit4:junit4] 2> 19396 T1973 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1860d6d main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 19396 T1974 C87 P58142 oash.SnapPuller.fetchLatestIndex removing temporary index download directory files MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c4b765 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1ea4705)
[junit4:junit4] 2> 19397 T1974 C87 P58142 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 19397 T1974 C87 P58142 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 19398 T1974 C87 P58142 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 19398 T1974 C87 P58142 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 19400 T1974 C87 P58142 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 19642 T1897 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 20125 T1920 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 20127 T1920 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44842",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:44842_"}
[junit4:junit4] 2> 20131 T1920 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58142",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:58142_"}
[junit4:junit4] 2> 20137 T1971 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> 20137 T1939 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> 20137 T1955 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> 20137 T1926 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> 20137 T1919 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> 20645 T1897 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 20646 T1897 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4] 2> 20646 T1897 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 20658 T1948 oejs.Response.sendError WARNING Committed before 404 Can not find: /onenodecollectioncore/update
[junit4:junit4] 2> 20658 T1897 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47139 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@18e0a5c
[junit4:junit4] 2> 20659 T1948 oejs.ServletHandler.doHandle WARNING /onenodecollectioncore/update java.lang.IllegalStateException: Committed
[junit4:junit4] 2> at org.eclipse.jetty.server.Response.resetBuffer(Response.java:1136)
[junit4:junit4] 2> at org.eclipse.jetty.server.Response.sendError(Response.java:314)
[junit4:junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$Servlet404.service(JettySolrRunner.java:465)
[junit4:junit4] 2> at javax.servlet.http.HttpServlet.service(HttpServlet.java:770)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:669)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1336)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:379)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:141)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1307)
[junit4:junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:135)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1307)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:453)
[junit4:junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.GzipHandler.handle(GzipHandler.java:275)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1074)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:382)
[junit4:junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1006)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
[junit4:junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:365)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:485)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:937)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:998)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:948)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:240)
[junit4:junit4] 2> at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)
[junit4:junit4] 2> at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:628)
[junit4:junit4] 2> at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52)
[junit4:junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4:junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2>
[junit4:junit4] 2> 20659 T1979 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47139. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 20659 T1897 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 20661 T1979 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47139, initiating session
[junit4:junit4] 2> 20661 T1899 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:47663
[junit4:junit4] 2> 20661 T1899 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:47663
[junit4:junit4] 2> 20662 T1901 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d55ef21b9000b with negotiated timeout 10000 for client /127.0.0.1:47663
[junit4:junit4] 2> 20662 T1979 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47139, sessionid = 0x13d55ef21b9000b, negotiated timeout = 10000
[junit4:junit4] 2> 20662 T1980 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18e0a5c name:ZooKeeperConnection Watcher:127.0.0.1:47139 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 20663 T1897 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 20695 T1902 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d55ef21b9000b
[junit4:junit4] 2> 20696 T1980 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 20696 T1899 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:47663 which had sessionid 0x13d55ef21b9000b
[junit4:junit4] 2> 20696 T1897 oaz.ZooKeeper.close Session: 0x13d55ef21b9000b closed
[junit4:junit4] 2> 20697 T1902 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d55ef21b90004
[junit4:junit4] 2> 20697 T1926 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 20697 T1897 oaz.ZooKeeper.close Session: 0x13d55ef21b90004 closed
[junit4:junit4] 2> 20697 T1899 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:47636 which had sessionid 0x13d55ef21b90004
[junit4:junit4] 2> 20699 T1897 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 48486
[junit4:junit4] 2> 20700 T1897 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=30627161
[junit4:junit4] 2> 21646 T1920 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 21647 T1920 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:48486__collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:48486",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:48486_"}
[junit4:junit4] 2> 21654 T1955 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> 21654 T1919 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> 21654 T1971 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> 21654 T1939 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> 22701 T1897 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 22702 T1897 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 22706 T1897 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@3d3035
[junit4:junit4] 2> 22720 T1897 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 22721 T1897 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 22722 T1897 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 22722 T1897 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 22723 T1897 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 22724 T1897 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/control/data
[junit4:junit4] 2> 22725 T1897 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/control/data
[junit4:junit4] 2> 22725 T1897 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/control/data/index
[junit4:junit4] 2> 22726 T1897 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/control/data/index
[junit4:junit4] 2> 22728 T1920 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89322053168594947-127.0.0.1:48486_-n_0000000000) am no longer a leader.
[junit4:junit4] 2> 22728 T1902 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d55ef21b90003
[junit4:junit4] 2> 22730 T1955 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> 22730 T1919 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> 22730 T1897 oaz.ZooKeeper.close Session: 0x13d55ef21b90003 closed
[junit4:junit4] 2> 22730 T1899 oazs.NIOServerCnxn.doIO WARNING caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13d55ef21b90003, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2>
[junit4:junit4] 2> 22731 T1919 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 22731 T1939 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 22731 T1971 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 22732 T1919 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 22732 T1899 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:47626 which had sessionid 0x13d55ef21b90003
[junit4:junit4] 2> 22733 T1971 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> 22732 T1939 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> 22733 T1919 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 22736 T1955 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 22737 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90006 type:delete cxid:0xbc zxid:0xce txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4] 2> 22738 T1939 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 22741 T1939 oasc.Overseer.start Overseer (id=89322053168594950-127.0.0.1:44842_-n_0000000001) starting
[junit4:junit4] 2> 22742 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90006 type:create cxid:0xc1 zxid:0xd0 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 22743 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90006 type:create cxid:0xc2 zxid:0xd1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 22744 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90006 type:create cxid:0xc3 zxid:0xd2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 22745 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90006 type:create cxid:0xc4 zxid:0xd3 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 22746 T1982 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 22747 T1981 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 22750 T1981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 22751 T1981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "base_url":"http://127.0.0.1:48486",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:48486_"}
[junit4:junit4] 2> 22753 T1897 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 22759 T1971 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> 22759 T1939 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> 22759 T1955 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> 22804 T1897 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 44842
[junit4:junit4] 2> 22804 T1897 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=6986405
[junit4:junit4] 2> 24264 T1981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 24266 T1981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:44842__collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44842",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:44842_"}
[junit4:junit4] 2> 24270 T1981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:44842__onenodecollectioncore",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44842",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:44842_"}
[junit4:junit4] 2> 24274 T1939 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> 24274 T1971 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> 24274 T1955 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> 25807 T1897 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 25808 T1897 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 25811 T1897 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> 25815 T1897 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@9080bd
[junit4:junit4] 2> 25821 T1897 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 25822 T1897 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 25822 T1897 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 25823 T1897 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 25826 T1897 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 25826 T1897 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty1
[junit4:junit4] 2> 25827 T1897 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty1
[junit4:junit4] 2> 25828 T1897 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty1/index
[junit4:junit4] 2> 25828 T1897 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty1/index
[junit4:junit4] 2> 25829 T1897 oasc.SolrCore.close [onenodecollectioncore] CLOSING SolrCore org.apache.solr.core.SolrCore@82fa6a
[junit4:junit4] 2> 25838 T1897 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 25839 T1897 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 25840 T1897 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 25840 T1897 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 25841 T1897 oasc.SolrCore.closeSearcher [onenodecollectioncore] Closing main searcher on request.
[junit4:junit4] 2> 25842 T1897 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362946367926/onenodecollection/index
[junit4:junit4] 2> 25842 T1897 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362946367926/onenodecollection/index
[junit4:junit4] 2> 25843 T1897 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362946367926/onenodecollection
[junit4:junit4] 2> 25844 T1897 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362946367926/onenodecollection
[junit4:junit4] 2> 25845 T1981 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89322053168594950-127.0.0.1:44842_-n_0000000001) am no longer a leader.
[junit4:junit4] 2> 25845 T1902 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d55ef21b90006
[junit4:junit4] 2> 25847 T1899 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:47640 which had sessionid 0x13d55ef21b90006
[junit4:junit4] 2> 25847 T1897 oaz.ZooKeeper.close Session: 0x13d55ef21b90006 closed
[junit4:junit4] 2> 25848 T1955 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 25849 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b9000a type:delete cxid:0x55 zxid:0xe4 txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard2 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard2
[junit4:junit4] 2> 25849 T1955 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> 25850 T1971 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 25850 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b9000a type:create cxid:0x56 zxid:0xe5 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 25852 T1971 oasc.ShardLeaderElectionContext.shouldIBeLeader Checking if I should try and be the leader.
[junit4:junit4] 2> 25853 T1971 oasc.ShardLeaderElectionContext.shouldIBeLeader My last published State was Active, it's okay to be the leader.
[junit4:junit4] 2> 25853 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90008 type:delete cxid:0x74 zxid:0xe7 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4] 2> 25853 T1971 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 25854 T1971 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58142/collection1/
[junit4:junit4] 2> 25854 T1955 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 25854 T1971 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:58142 START replicas=[http://127.0.0.1:44842/collection1/] nUpdates=100
[junit4:junit4] 2> 25855 T1971 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:58142 DONE. We have no versions. sync failed.
[junit4:junit4] 2> 25855 T1971 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 25855 T1971 oasc.ShardLeaderElectionContext.runLeaderProcess We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4:junit4] 2> 25856 T1971 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58142/collection1/
[junit4:junit4] 2> 25856 T1971 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 25857 T1955 oasc.Overseer.start Overseer (id=89322053168594952-127.0.0.1:44284_-n_0000000002) starting
[junit4:junit4] 2> 25858 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90008 type:create cxid:0x79 zxid:0xe9 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 25859 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90008 type:create cxid:0x7a zxid:0xea txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 25860 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90008 type:create cxid:0x7b zxid:0xec txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 25862 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b9000a type:create cxid:0x5e zxid:0xed txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 25862 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b90008 type:create cxid:0x7c zxid:0xee txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 25863 T1985 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 25864 T1971 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> 25865 T1984 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 25866 T1971 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 25868 T1984 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 25870 T1984 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44842",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:44842_"}
[junit4:junit4] 2> 25870 T1897 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 25875 T1984 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44842",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:44842_"}
[junit4:junit4] 2> 25888 T1955 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> 25888 T1971 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> 25923 T1897 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 44284
[junit4:junit4] 2> 25924 T1897 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=3699409
[junit4:junit4] 2> 26926 T1897 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 26927 T1897 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 26931 T1897 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@932883
[junit4:junit4] 2> 26937 T1897 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 26938 T1897 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 26938 T1897 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 26939 T1897 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 26941 T1897 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 26941 T1897 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty2
[junit4:junit4] 2> 26942 T1897 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty2
[junit4:junit4] 2> 26942 T1897 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty2/index
[junit4:junit4] 2> 26943 T1897 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty2/index
[junit4:junit4] 2> 26944 T1984 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89322053168594952-127.0.0.1:44284_-n_0000000002) am no longer a leader.
[junit4:junit4] 2> 26945 T1902 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d55ef21b90008
[junit4:junit4] 2> 26947 T1899 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:47646 which had sessionid 0x13d55ef21b90008
[junit4:junit4] 2> 26947 T1955 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> 26948 T1897 oaz.ZooKeeper.close Session: 0x13d55ef21b90008 closed
[junit4:junit4] 2> 26948 T1955 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 26949 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b9000a type:delete cxid:0x66 zxid:0x100 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4] 2> 26949 T1955 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 26950 T1955 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 26950 T1971 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 26953 T1971 oasc.Overseer.start Overseer (id=89322053168594954-127.0.0.1:58142_-n_0000000003) starting
[junit4:junit4] 2> 26954 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b9000a type:create cxid:0x6b zxid:0x102 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 26955 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b9000a type:create cxid:0x6c zxid:0x103 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 26957 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b9000a type:create cxid:0x6d zxid:0x104 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 26958 T1902 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d55ef21b9000a type:create cxid:0x6e zxid:0x105 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 26959 T1987 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 26959 T1971 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> 26962 T1971 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4:junit4] 2> 26963 T1986 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 26965 T1986 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 26966 T1986 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:44284__collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44284",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:44284_"}
[junit4:junit4] 2> 26970 T1986 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44284",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:44284_"}
[junit4:junit4] 2> 26970 T1897 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 26975 T1971 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> 27023 T1897 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 58142
[junit4:junit4] 2> 27023 T1897 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=18773593
[junit4:junit4] 2> 27147 T1939 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 27148 T1939 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> 27148 T1939 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 27148 T1939 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 28026 T1897 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 28026 T1897 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 28030 T1897 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1b8dd26
[junit4:junit4] 2> 28041 T1897 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 28042 T1897 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 28043 T1897 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 28044 T1897 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 28046 T1897 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 28047 T1897 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty3/index
[junit4:junit4] 2> 28047 T1897 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty3/index
[junit4:junit4] 2> 28048 T1897 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty3
[junit4:junit4] 2> 28049 T1897 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty3
[junit4:junit4] 2> 28049 T1897 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty3/index.20130310161307304
[junit4:junit4] 2> 28050 T1897 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362946367926/jetty3/index.20130310161307304
[junit4:junit4] 2> 28051 T1986 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89322053168594954-127.0.0.1:58142_-n_0000000003) am no longer a leader.
[junit4:junit4] 2> 28051 T1902 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d55ef21b9000a
[junit4:junit4] 2> 28053 T1899 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:47650 which had sessionid 0x13d55ef21b9000a
[junit4:junit4] 2> 28053 T1897 oaz.ZooKeeper.close Session: 0x13d55ef21b9000a closed
[junit4:junit4] 2> 28076 T1897 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 28132 T1897 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 28133 T1897 oazs.ZooKeeperServer.shutdown shutting down
[junit4:junit4] 2> 28133 T1897 oazs.SessionTrackerImpl.shutdown Shutting down
[junit4:junit4] 2> 28134 T1897 oazs.PrepRequestProcessor.shutdown Shutting down
[junit4:junit4] 2> 28135 T1902 oazs.PrepRequestProcessor.run PrepRequestProcessor exited loop!
[junit4:junit4] 2> 28135 T1897 oazs.SyncRequestProcessor.shutdown Shutting down
[junit4:junit4] 2> 28136 T1901 oazs.SyncRequestProcessor.run SyncRequestProcessor exited!
[junit4:junit4] 2> 28136 T1897 oazs.FinalRequestProcessor.shutdown shutdown of request processor complete
[junit4:junit4] 2> 28138 T1897 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:47139 47139
[junit4:junit4] 2> 28140 T1899 oazs.NIOServerCnxnFactory.run NIOServerCnxn factory exited run method
[junit4:junit4] 2> 28140 T1897 oazs.ZooKeeperServer.shutdown shutting down
[junit4:junit4] 2> 28141 T1897 oazs.SessionTrackerImpl.shutdown Shutting down
[junit4:junit4] 2> 28142 T1897 oazs.PrepRequestProcessor.shutdown Shutting down
[junit4:junit4] 2> 28142 T1897 oazs.SyncRequestProcessor.shutdown Shutting down
[junit4:junit4] 2> 28143 T1897 oazs.FinalRequestProcessor.shutdown shutdown of request processor complete
[junit4:junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4] 1> / (2)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1> /solr (7)
[junit4:junit4] 1> /solr/overseer_elect (2)
[junit4:junit4] 1> /solr/overseer_elect/leader (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"id":"89322053168594947-127.0.0.1:48486_-n_0000000000"}
[junit4:junit4] 1> /solr/overseer_elect/election (4)
[junit4:junit4] 1> /solr/overseer_elect/election/89322053168594950-127.0.0.1:44842_-n_0000000001 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89322053168594954-127.0.0.1:58142_-n_0000000003 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89322053168594952-127.0.0.1:44284_-n_0000000002 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89322053168594947-127.0.0.1:48486_-n_0000000000 (0)
[junit4:junit4] 1> /solr/overseer (3)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1> /solr/overseer/queue (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1> /solr/overseer/collection-queue-work (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1> /solr/overseer/queue-work (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1> /solr/aliases.json (0)
[junit4:junit4] 1> /solr/collections (3)
[junit4:junit4] 1> /solr/collections/collection1 (3)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"configName":"conf1"}
[junit4:junit4] 1> /solr/collections/collection1/leaders (2)
[junit4:junit4] 1> /solr/collections/collection1/leaders/shard1 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "base_url":"http://127.0.0.1:44284",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "node_name":"127.0.0.1:44284_"}
[junit4:junit4] 1> /solr/collections/collection1/leaders/shard2 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "base_url":"http://127.0.0.1:44842",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "node_name":"127.0.0.1:44842_"}
[junit4:junit4] 1> /solr/collections/collection1/leader_elect (2)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1 (1)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election (1)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/89322053168594952-127.0.0.1:44284__collection1-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2 (1)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2/election (2)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2/election/89322053168594950-127.0.0.1:44842__collection1-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2/election/89322053168594954-127.0.0.1:58142__collection1-n_0000000001 (0)
[junit4:junit4] 1> /solr/collections/collection1/shards (0)
[junit4:junit4] 1> /solr/collections/control_collection (3)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"configName":"conf1"}
[junit4:junit4] 1> /solr/collections/control_collection/leaders (1)
[junit4:junit4] 1> /solr/collections/control_collection/leaders/shard1 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "base_url":"http://127.0.0.1:48486",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "node_name":"127.0.0.1:48486_"}
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect (1)
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect/shard1 (1)
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election (1)
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election/89322053168594947-127.0.0.1:48486__collection1-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/control_collection/shards (0)
[junit4:junit4] 1> /solr/collections/onenodecollection (2)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "configName":"conf1",
[junit4:junit4] 1> "router":"compositeId"}
[junit4:junit4] 1> /solr/collections/onenodecollection/leaders (1)
[junit4:junit4] 1> /solr/collections/onenodecollection/leaders/shard1 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "base_url":"http://127.0.0.1:44842",
[junit4:junit4] 1> "core":"onenodecollectioncore",
[junit4:junit4] 1> "node_name":"127.0.0.1:44842_"}
[junit4:junit4] 1> /solr/collections/onenodecollection/leader_elect (1)
[junit4:junit4] 1> /solr/collections/onenodecollection/leader_elect/shard1 (1)
[junit4:junit4] 1> /solr/collections/onenodecollection/leader_elect/shard1/election (1)
[junit4:junit4] 1> /solr/collections/onenodecollection/leader_elect/shard1/election/89322053168594950-127.0.0.1:44842__onenodecollectioncore-n_0000000000 (0)
[junit4:junit4] 1> /solr/clusterstate.json (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "collection1":{
[junit4:junit4] 1> "router":"compositeId",
[junit4:junit4] 1> "shards":{
[junit4:junit4] 1> "shard2":{
[junit4:junit4] 1> "range":"0-7fffffff",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "replicas":{
[junit4:junit4] 1> "127.0.0.1:44842__collection1":{
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "shard":"shard2",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:44842",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "node_name":"127.0.0.1:44842_",
[junit4:junit4] 1> "leader":"true"},
[junit4:junit4] 1> "127.0.0.1:58142__collection1":{
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "shard":"shard2",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:58142",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "node_name":"127.0.0.1:58142_"}}},
[junit4:junit4] 1> "shard1":{
[junit4:junit4] 1> "range":"80000000-ffffffff",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "replicas":{"127.0.0.1:44284__collection1":{
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:44284",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "node_name":"127.0.0.1:44284_",
[junit4:junit4] 1> "leader":"true"}}}}},
[junit4:junit4] 1> "control_collection":{
[junit4:junit4] 1> "router":"compositeId",
[junit4:junit4] 1> "shards":{"shard1":{
[junit4:junit4] 1> "range":"80000000-7fffffff",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "replicas":{"127.0.0.1:48486__collection1":{
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "collection":"control_collection",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:48486",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "node_name":"127.0.0.1:48486_",
[junit4:junit4] 1> "leader":"true"}}}}},
[junit4:junit4] 1> "onenodecollection":{
[junit4:junit4] 1> "router":"composit
[...truncated too long message...]
/mapping-ISOLatin1Accent.txt (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/protwords.txt (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/synonyms.txt (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/live_nodes (5)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:43540_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:49039_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:48284_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:34930_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:56673_ (0)
[junit4:junit4] 1> /zookeeper (1)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1>
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=UnloadDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=1DAFA987D21579E1 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=fi_FI -Dtests.timezone=Europe/Istanbul -Dtests.file.encoding=UTF-8
[junit4:junit4] FAILURE 134s J1 | UnloadDistributedZkTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: java.lang.AssertionError: Still found shard
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([1DAFA987D21579E1:9C49279FA54A19DD]:0)
[junit4:junit4] > at org.junit.Assert.fail(Assert.java:93)
[junit4:junit4] > at org.apache.solr.cloud.UnloadDistributedZkTest.testUnloadShardAndCollection(UnloadDistributedZkTest.java:124)
[junit4:junit4] > at org.apache.solr.cloud.UnloadDistributedZkTest.doTest(UnloadDistributedZkTest.java:77)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
[junit4:junit4] > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4:junit4] > at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4:junit4] > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4:junit4] > at java.lang.reflect.Method.invoke(Method.java:487)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4] > at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4:junit4] > at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4:junit4] > at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4] > at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4:junit4] > at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4] > at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4] > at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4] > at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] > at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4] > at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4] > at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4] > at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 133841 T1989 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 133854 T1988 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4] 2> 134432 T1992 oazs.SessionTrackerImpl.run SessionTrackerImpl exited loop!
[junit4:junit4] 2> NOTE: test params are: codec=Lucene3x, sim=DefaultSimilarity, locale=fi_FI, timezone=Europe/Istanbul
[junit4:junit4] 2> NOTE: Linux 3.2.0-38-generic i386/Oracle Corporation 1.8.0-ea (32-bit)/cpus=8,threads=2,free=133903216,total=206024704
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestComponentsName, DistanceFunctionTest, TestQuerySenderNoQuery, TestFoldingMultitermQuery, StandardRequestHandlerTest, ChaosMonkeySafeLeaderTest, TestBinaryField, SolrIndexConfigTest, TestRandomFaceting, TestCopyFieldCollectionResource, CoreContainerCoreInitFailuresTest, TestCSVResponseWriter, NoCacheHeaderTest, DOMUtilTest, SampleTest, OutputWriterTest, DateMathParserTest, TestSolrDiscoveryProperties, UpdateParamsTest, TestQueryTypes, TestElisionMultitermQuery, TestCSVLoader, TestLazyCores, TimeZoneUtilsTest, OpenExchangeRatesOrgProviderTest, TestCollationField, XsltUpdateRequestHandlerTest, TestMultiCoreConfBootstrap, BasicZkTest, TestIndexingPerformance, IndexSchemaRuntimeFieldTest, DirectSolrSpellCheckerTest, TestStressReorder, RequiredFieldsTest, SpellCheckCollatorTest, TestJmxMonitoredMap, IndexBasedSpellCheckerTest, ZkSolrClientTest, StatsComponentTest, BadIndexSchemaTest, TestPartialUpdateDeduplication, TestLMJelinekMercerSimilarityFactory, SortByFunctionTest, DefaultValueUpdateProcessorTest, FieldAnalysisRequestHandlerTest, SolrPluginUtilsTest, TestUtils, CurrencyFieldXmlFileTest, TestArbitraryIndexDir, FullSolrCloudDistribCmdsTest, NumericFieldsTest, DocValuesMultiTest, TestZkChroot, TermVectorComponentDistributedTest, TestDynamicFieldCollectionResource, ConvertedLegacyTest, TestCollationKeyRangeQueries, CollectionsAPIDistributedZkTest, TestAtomicUpdateErrorCases, SuggesterWFSTTest, LeaderElectionIntegrationTest, SolrCmdDistributorTest, HighlighterTest, TestSuggestSpellingConverter, BasicDistributedZk2Test, UnloadDistributedZkTest]
[junit4:junit4] Completed on J1 in 134.63s, 1 test, 1 failure <<< FAILURES!
[...truncated 408 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:381: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:361: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:183: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:449: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1213: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:877: There were test failures: 270 suites, 1140 tests, 1 error, 1 failure, 14 ignored (8 assumptions)
Total time: 54 minutes 33 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 32bit/jdk1.8.0-ea-b79 -client -XX:+UseConcMarkSweepGC
Email was triggered for: Failure
Sending email for trigger: Failure