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/09 03:26:11 UTC
[JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.8.0-ea-b79) - Build #
4632 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/4632/
Java: 64bit/jdk1.8.0-ea-b79 -XX:+UseSerialGC
1 tests failed.
FAILED: org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch
Error Message:
Server at http://127.0.0.1:42169/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:42169/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
at __randomizedtesting.SeedInfo.seed([F53F4F2F50EDCCEC:74D9C13727B2ACD0]: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)
Build Log:
[...truncated 9172 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4] 2> 0 T2360 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 3 T2360 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362795534761
[junit4:junit4] 2> 4 T2360 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 4 T2361 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 5 T2361 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4] 2> 5 T2361 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4] 2> 5 T2361 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4] 2> 5 T2361 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> 6 T2361 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4] 2> 104 T2360 oasc.ZkTestServer.run start zk server on port:52788
[junit4:junit4] 2> 105 T2360 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52788 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@45d336df
[junit4:junit4] 2> 106 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 106 T2366 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:52788. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 107 T2366 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:52788, initiating session
[junit4:junit4] 2> 107 T2362 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50641
[junit4:junit4] 2> 107 T2362 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50641
[junit4:junit4] 2> 107 T2364 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4] 2> 146 T2364 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4cf199ac0000 with negotiated timeout 10000 for client /127.0.0.1:50641
[junit4:junit4] 2> 146 T2366 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:52788, sessionid = 0x13d4cf199ac0000, negotiated timeout = 10000
[junit4:junit4] 2> 147 T2367 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@45d336df name:ZooKeeperConnection Watcher:127.0.0.1:52788 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 147 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 147 T2360 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 150 T2365 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4cf199ac0000
[junit4:junit4] 2> 151 T2367 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 151 T2360 oaz.ZooKeeper.close Session: 0x13d4cf199ac0000 closed
[junit4:junit4] 2> 151 T2362 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50641 which had sessionid 0x13d4cf199ac0000
[junit4:junit4] 2> 151 T2360 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52788/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@4b14c015
[junit4:junit4] 2> 152 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 152 T2368 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:52788. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 152 T2368 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:52788, initiating session
[junit4:junit4] 2> 152 T2362 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50642
[junit4:junit4] 2> 153 T2362 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50642
[junit4:junit4] 2> 153 T2364 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4cf199ac0001 with negotiated timeout 10000 for client /127.0.0.1:50642
[junit4:junit4] 2> 153 T2368 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:52788, sessionid = 0x13d4cf199ac0001, negotiated timeout = 10000
[junit4:junit4] 2> 153 T2369 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b14c015 name:ZooKeeperConnection Watcher:127.0.0.1:52788/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 154 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 154 T2360 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 156 T2360 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 158 T2360 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 160 T2360 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 161 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 162 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 164 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 165 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 167 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 167 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 169 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 169 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 172 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 173 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 176 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 176 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 177 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 178 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 180 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 180 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 182 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 182 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 184 T2365 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4cf199ac0001
[junit4:junit4] 2> 184 T2369 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 184 T2362 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50642 which had sessionid 0x13d4cf199ac0001
[junit4:junit4] 2> 184 T2360 oaz.ZooKeeper.close Session: 0x13d4cf199ac0001 closed
[junit4:junit4] 2> 261 T2360 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 267 T2360 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:४२९११
[junit4:junit4] 2> 268 T2360 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 268 T2360 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 268 T2360 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362795534942
[junit4:junit4] 2> 269 T2360 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362795534942/solr.xml
[junit4:junit4] 2> 269 T2360 oasc.CoreContainer.<init> New CoreContainer 901688613
[junit4:junit4] 2> 269 T2360 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362795534942/'
[junit4:junit4] 2> 270 T2360 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362795534942/'
[junit4:junit4] 2> 288 T2360 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 289 T2360 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 289 T2360 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 289 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 290 T2360 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 290 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 290 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 291 T2360 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 291 T2360 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 291 T2360 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 297 T2360 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 306 T2360 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:52788/solr
[junit4:junit4] 2> 306 T2360 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 307 T2360 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52788 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@295ce096
[junit4:junit4] 2> 307 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 308 T2379 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:52788. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 308 T2379 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:52788, initiating session
[junit4:junit4] 2> 308 T2362 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50643
[junit4:junit4] 2> 309 T2362 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50643
[junit4:junit4] 2> 309 T2364 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4cf199ac0002 with negotiated timeout 20000 for client /127.0.0.1:50643
[junit4:junit4] 2> 309 T2379 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:52788, sessionid = 0x13d4cf199ac0002, negotiated timeout = 20000
[junit4:junit4] 2> 310 T2380 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@295ce096 name:ZooKeeperConnection Watcher:127.0.0.1:52788 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 310 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 311 T2365 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4cf199ac0002
[junit4:junit4] 2> 311 T2380 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 311 T2362 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50643 which had sessionid 0x13d4cf199ac0002
[junit4:junit4] 2> 311 T2360 oaz.ZooKeeper.close Session: 0x13d4cf199ac0002 closed
[junit4:junit4] 2> 312 T2360 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 314 T2360 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52788/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@c46c902
[junit4:junit4] 2> 315 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 324 T2381 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:52788. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 324 T2381 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:52788, initiating session
[junit4:junit4] 2> 325 T2362 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50644
[junit4:junit4] 2> 325 T2362 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50644
[junit4:junit4] 2> 326 T2364 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4cf199ac0003 with negotiated timeout 20000 for client /127.0.0.1:50644
[junit4:junit4] 2> 326 T2381 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:52788, sessionid = 0x13d4cf199ac0003, negotiated timeout = 20000
[junit4:junit4] 2> 326 T2382 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c46c902 name:ZooKeeperConnection Watcher:127.0.0.1:52788/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 326 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 328 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 329 T2360 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 330 T2360 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42911_
[junit4:junit4] 2> 331 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:42911_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:42911_
[junit4:junit4] 2> 331 T2360 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42911_
[junit4:junit4] 2> 333 T2360 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 336 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0003 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> 336 T2360 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 339 T2360 oasc.Overseer.start Overseer (id=89312168166293507-127.0.0.1:42911_-n_0000000000) starting
[junit4:junit4] 2> 339 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 340 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 340 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 341 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 341 T2384 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 341 T2360 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 343 T2360 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 344 T2360 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 346 T2383 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 348 T2385 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362795534942/collection1
[junit4:junit4] 2> 348 T2385 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 348 T2385 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 348 T2385 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 349 T2385 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362795534942/collection1/'
[junit4:junit4] 2> 350 T2385 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362795534942/collection1/lib/README' to classloader
[junit4:junit4] 2> 350 T2385 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362795534942/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 384 T2385 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 409 T2385 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 410 T2385 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 413 T2385 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 717 T2385 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 723 T2385 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 724 T2385 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 739 T2385 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 744 T2385 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 747 T2385 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 748 T2385 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 749 T2385 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 749 T2385 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 750 T2385 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 750 T2385 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 750 T2385 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362795534942/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/control/data/
[junit4:junit4] 2> 751 T2385 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@287492a0
[junit4:junit4] 2> 751 T2385 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 752 T2385 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/control/data forceNew: false
[junit4:junit4] 2> 752 T2385 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/control/data/index/
[junit4:junit4] 2> 752 T2385 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 753 T2385 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/control/data/index forceNew: false
[junit4:junit4] 2> 755 T2385 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@3de76735 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6ac22245),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 755 T2385 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 756 T2385 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 757 T2385 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 757 T2385 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 758 T2385 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 758 T2385 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 758 T2385 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 758 T2385 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 759 T2385 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 759 T2385 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 763 T2385 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 765 T2385 oass.SolrIndexSearcher.<init> Opening Searcher@4e8c1465 main
[junit4:junit4] 2> 766 T2385 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/control/data/tlog
[junit4:junit4] 2> 766 T2385 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 766 T2385 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 768 T2386 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4e8c1465 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 768 T2385 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 769 T2385 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 769 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0003 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> 1848 T2383 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1849 T2383 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42911",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "node_name":"127.0.0.1:42911_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"down"}
[junit4:junit4] 2> 1849 T2383 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 1849 T2383 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 1850 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0003 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> 1853 T2382 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> 2771 T2385 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2771 T2385 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42911 collection:control_collection shard:shard1
[junit4:junit4] 2> 2772 T2385 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2777 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0003 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> 2777 T2385 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2777 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0003 type:create cxid:0x78 zxid:0x38 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 2779 T2385 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2779 T2385 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2779 T2385 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:42911/collection1/
[junit4:junit4] 2> 2779 T2385 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2779 T2385 oasc.SyncStrategy.syncToMe http://127.0.0.1:42911/collection1/ has no replicas
[junit4:junit4] 2> 2779 T2385 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:42911/collection1/
[junit4:junit4] 2> 2779 T2385 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 2782 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0003 type:create cxid:0x82 zxid:0x3c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3355 T2383 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3362 T2382 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> 3385 T2385 oasc.ZkController.register We are http://127.0.0.1:42911/collection1/ and leader is http://127.0.0.1:42911/collection1/
[junit4:junit4] 2> 3385 T2385 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42911
[junit4:junit4] 2> 3385 T2385 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 3385 T2385 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 3385 T2385 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 3387 T2385 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3388 T2360 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 3388 T2360 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 3388 T2360 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 3391 T2360 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 3392 T2360 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52788/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@4501087
[junit4:junit4] 2> 3393 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3393 T2388 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:52788. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3394 T2388 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:52788, initiating session
[junit4:junit4] 2> 3394 T2362 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50646
[junit4:junit4] 2> 3394 T2362 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50646
[junit4:junit4] 2> 3395 T2364 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4cf199ac0004 with negotiated timeout 10000 for client /127.0.0.1:50646
[junit4:junit4] 2> 3395 T2388 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:52788, sessionid = 0x13d4cf199ac0004, negotiated timeout = 10000
[junit4:junit4] 2> 3395 T2389 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4501087 name:ZooKeeperConnection Watcher:127.0.0.1:52788/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3395 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3397 T2360 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 3398 T2360 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 3462 T2360 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 3464 T2360 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:५४२५५
[junit4:junit4] 2> 3464 T2360 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 3465 T2360 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 3465 T2360 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362795538155
[junit4:junit4] 2> 3465 T2360 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362795538155/solr.xml
[junit4:junit4] 2> 3466 T2360 oasc.CoreContainer.<init> New CoreContainer 21725380
[junit4:junit4] 2> 3466 T2360 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362795538155/'
[junit4:junit4] 2> 3466 T2360 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362795538155/'
[junit4:junit4] 2> 3482 T2360 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 3482 T2360 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 3482 T2360 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 3483 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 3483 T2360 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 3483 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 3483 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 3484 T2360 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 3484 T2360 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 3484 T2360 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 3490 T2360 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 3498 T2360 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:52788/solr
[junit4:junit4] 2> 3499 T2360 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 3499 T2360 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52788 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@7432d7d7
[junit4:junit4] 2> 3500 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3500 T2399 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:52788. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3501 T2399 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:52788, initiating session
[junit4:junit4] 2> 3501 T2362 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50647
[junit4:junit4] 2> 3501 T2362 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50647
[junit4:junit4] 2> 3502 T2364 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4cf199ac0005 with negotiated timeout 20000 for client /127.0.0.1:50647
[junit4:junit4] 2> 3502 T2399 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:52788, sessionid = 0x13d4cf199ac0005, negotiated timeout = 20000
[junit4:junit4] 2> 3502 T2400 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7432d7d7 name:ZooKeeperConnection Watcher:127.0.0.1:52788 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3502 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3503 T2365 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4cf199ac0005
[junit4:junit4] 2> 3504 T2400 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 3504 T2362 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50647 which had sessionid 0x13d4cf199ac0005
[junit4:junit4] 2> 3504 T2360 oaz.ZooKeeper.close Session: 0x13d4cf199ac0005 closed
[junit4:junit4] 2> 3504 T2360 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 3507 T2360 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52788/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@5a0f9fe6
[junit4:junit4] 2> 3507 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3508 T2401 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:52788. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3508 T2401 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:52788, initiating session
[junit4:junit4] 2> 3508 T2362 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50648
[junit4:junit4] 2> 3508 T2362 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50648
[junit4:junit4] 2> 3509 T2364 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4cf199ac0006 with negotiated timeout 20000 for client /127.0.0.1:50648
[junit4:junit4] 2> 3509 T2401 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:52788, sessionid = 0x13d4cf199ac0006, negotiated timeout = 20000
[junit4:junit4] 2> 3510 T2402 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5a0f9fe6 name:ZooKeeperConnection Watcher:127.0.0.1:52788/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3510 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3511 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0006 type:create cxid:0x1 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3512 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0006 type:create cxid:0x2 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3513 T2360 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 4515 T2360 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54255_
[junit4:junit4] 2> 4516 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0006 type:delete cxid:0xb zxid:0x4c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:54255_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:54255_
[junit4:junit4] 2> 4516 T2360 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54255_
[junit4:junit4] 2> 4518 T2382 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> 4519 T2389 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4519 T2402 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4519 T2382 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4523 T2403 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362795538155/collection1
[junit4:junit4] 2> 4523 T2403 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 4524 T2403 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 4524 T2403 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 4525 T2403 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362795538155/collection1/'
[junit4:junit4] 2> 4525 T2403 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362795538155/collection1/lib/README' to classloader
[junit4:junit4] 2> 4526 T2403 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362795538155/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 4554 T2403 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 4602 T2403 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 4603 T2403 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 4607 T2403 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 4866 T2383 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 4866 T2383 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42911",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "node_name":"127.0.0.1:42911_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"active"}
[junit4:junit4] 2> 4869 T2402 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> 4869 T2389 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> 4869 T2382 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> 4965 T2403 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 4974 T2403 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 4977 T2403 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 4988 T2403 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 4992 T2403 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 4996 T2403 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 4996 T2403 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 4997 T2403 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 4997 T2403 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 4998 T2403 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 4998 T2403 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 4999 T2403 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362795538155/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty1/
[junit4:junit4] 2> 4999 T2403 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@287492a0
[junit4:junit4] 2> 5000 T2403 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 5000 T2403 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty1 forceNew: false
[junit4:junit4] 2> 5001 T2403 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty1/index/
[junit4:junit4] 2> 5001 T2403 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 5001 T2403 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty1/index forceNew: false
[junit4:junit4] 2> 5003 T2403 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4c704776 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6e0a958e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 5004 T2403 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 5006 T2403 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 5006 T2403 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 5007 T2403 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 5007 T2403 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 5008 T2403 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 5008 T2403 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 5008 T2403 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 5008 T2403 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 5009 T2403 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 5012 T2403 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 5014 T2403 oass.SolrIndexSearcher.<init> Opening Searcher@7149342 main
[junit4:junit4] 2> 5014 T2403 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty1/tlog
[junit4:junit4] 2> 5015 T2403 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 5015 T2403 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 5019 T2404 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7149342 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 5020 T2403 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 5021 T2403 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 6373 T2383 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 6374 T2383 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:54255",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:54255_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"down"}
[junit4:junit4] 2> 6374 T2383 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 6374 T2383 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 6377 T2402 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> 6377 T2382 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> 6377 T2389 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> 7022 T2403 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 7022 T2403 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54255 collection:collection1 shard:shard2
[junit4:junit4] 2> 7023 T2403 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 7027 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0006 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> 7028 T2403 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 7028 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0006 type:create cxid:0x49 zxid:0x5d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 7029 T2403 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 7030 T2403 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 7030 T2403 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54255/collection1/
[junit4:junit4] 2> 7030 T2403 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 7030 T2403 oasc.SyncStrategy.syncToMe http://127.0.0.1:54255/collection1/ has no replicas
[junit4:junit4] 2> 7030 T2403 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54255/collection1/
[junit4:junit4] 2> 7030 T2403 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 7033 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0006 type:create cxid:0x53 zxid:0x61 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 7880 T2383 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 7886 T2382 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> 7886 T2389 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> 7886 T2402 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> 7937 T2403 oasc.ZkController.register We are http://127.0.0.1:54255/collection1/ and leader is http://127.0.0.1:54255/collection1/
[junit4:junit4] 2> 7937 T2403 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54255
[junit4:junit4] 2> 7937 T2403 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 7937 T2403 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 7937 T2403 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 7939 T2403 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 7940 T2360 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 7940 T2360 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 7941 T2360 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 8011 T2360 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 8013 T2360 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:४२१६९
[junit4:junit4] 2> 8014 T2360 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 8014 T2360 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 8015 T2360 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362795542703
[junit4:junit4] 2> 8015 T2360 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362795542703/solr.xml
[junit4:junit4] 2> 8015 T2360 oasc.CoreContainer.<init> New CoreContainer 1074483858
[junit4:junit4] 2> 8016 T2360 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362795542703/'
[junit4:junit4] 2> 8016 T2360 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362795542703/'
[junit4:junit4] 2> 8031 T2360 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 8032 T2360 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 8032 T2360 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 8032 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 8032 T2360 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 8033 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 8033 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 8033 T2360 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 8033 T2360 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 8034 T2360 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 8039 T2360 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 8047 T2360 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:52788/solr
[junit4:junit4] 2> 8048 T2360 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 8048 T2360 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52788 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@3cd6549e
[junit4:junit4] 2> 8049 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8049 T2415 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:52788. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 8050 T2415 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:52788, initiating session
[junit4:junit4] 2> 8050 T2362 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50660
[junit4:junit4] 2> 8050 T2362 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50660
[junit4:junit4] 2> 8052 T2364 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4cf199ac0007 with negotiated timeout 20000 for client /127.0.0.1:50660
[junit4:junit4] 2> 8052 T2415 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:52788, sessionid = 0x13d4cf199ac0007, negotiated timeout = 20000
[junit4:junit4] 2> 8052 T2416 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3cd6549e name:ZooKeeperConnection Watcher:127.0.0.1:52788 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8052 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8054 T2365 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4cf199ac0007
[junit4:junit4] 2> 8054 T2416 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 8054 T2362 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50660 which had sessionid 0x13d4cf199ac0007
[junit4:junit4] 2> 8054 T2360 oaz.ZooKeeper.close Session: 0x13d4cf199ac0007 closed
[junit4:junit4] 2> 8055 T2360 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 8057 T2360 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52788/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@56aeb665
[junit4:junit4] 2> 8058 T2417 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:52788. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 8058 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8059 T2417 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:52788, initiating session
[junit4:junit4] 2> 8059 T2362 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50661
[junit4:junit4] 2> 8059 T2362 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50661
[junit4:junit4] 2> 8060 T2364 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4cf199ac0008 with negotiated timeout 20000 for client /127.0.0.1:50661
[junit4:junit4] 2> 8060 T2417 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:52788, sessionid = 0x13d4cf199ac0008, negotiated timeout = 20000
[junit4:junit4] 2> 8060 T2418 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@56aeb665 name:ZooKeeperConnection Watcher:127.0.0.1:52788/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8060 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8061 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0008 type:create cxid:0x1 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8062 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0008 type:create cxid:0x2 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8063 T2360 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 9066 T2360 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42169_
[junit4:junit4] 2> 9067 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0008 type:delete cxid:0xb zxid:0x70 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:42169_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:42169_
[junit4:junit4] 2> 9067 T2360 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42169_
[junit4:junit4] 2> 9069 T2389 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> 9069 T2402 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9069 T2382 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9069 T2402 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> 9069 T2382 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> 9071 T2418 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9071 T2389 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9075 T2419 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362795542703/collection1
[junit4:junit4] 2> 9075 T2419 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 9075 T2419 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 9076 T2419 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 9076 T2419 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362795542703/collection1/'
[junit4:junit4] 2> 9077 T2419 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362795542703/collection1/lib/README' to classloader
[junit4:junit4] 2> 9077 T2419 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362795542703/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 9097 T2419 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 9133 T2419 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 9134 T2419 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 9137 T2419 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 9390 T2383 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 9391 T2383 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:54255",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:54255_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"active"}
[junit4:junit4] 2> 9394 T2382 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> 9394 T2402 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> 9394 T2389 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> 9394 T2418 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> 9438 T2419 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 9443 T2419 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 9445 T2419 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 9455 T2419 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 9458 T2419 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 9460 T2419 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 9461 T2419 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 9461 T2419 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 9461 T2419 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 9462 T2419 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 9462 T2419 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 9462 T2419 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362795542703/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty2/
[junit4:junit4] 2> 9462 T2419 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@287492a0
[junit4:junit4] 2> 9463 T2419 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 9463 T2419 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty2 forceNew: false
[junit4:junit4] 2> 9463 T2419 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty2/index/
[junit4:junit4] 2> 9464 T2419 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 9464 T2419 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty2/index forceNew: false
[junit4:junit4] 2> 9465 T2419 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@21289391 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2680e416),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 9465 T2419 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 9466 T2419 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 9466 T2419 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 9467 T2419 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 9467 T2419 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 9468 T2419 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 9468 T2419 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 9468 T2419 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 9468 T2419 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 9468 T2419 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 9470 T2419 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 9472 T2419 oass.SolrIndexSearcher.<init> Opening Searcher@7ae177a main
[junit4:junit4] 2> 9473 T2419 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty2/tlog
[junit4:junit4] 2> 9473 T2419 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 9473 T2419 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 9476 T2420 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7ae177a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 9477 T2419 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 9477 T2419 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 10898 T2383 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 10899 T2383 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42169",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:42169_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"down"}
[junit4:junit4] 2> 10899 T2383 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 10899 T2383 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 10902 T2382 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> 10902 T2389 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> 10902 T2402 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> 10902 T2418 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> 11478 T2419 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 11478 T2419 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42169 collection:collection1 shard:shard1
[junit4:junit4] 2> 11479 T2419 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 11485 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0008 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> 11485 T2419 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 11486 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0008 type:create cxid:0x48 zxid:0x80 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 11487 T2419 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 11487 T2419 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 11487 T2419 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:42169/collection1/
[junit4:junit4] 2> 11487 T2419 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 11488 T2419 oasc.SyncStrategy.syncToMe http://127.0.0.1:42169/collection1/ has no replicas
[junit4:junit4] 2> 11488 T2419 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:42169/collection1/
[junit4:junit4] 2> 11488 T2419 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 11490 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0008 type:create cxid:0x51 zxid:0x83 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 12406 T2383 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 12411 T2389 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> 12411 T2382 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> 12411 T2402 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> 12412 T2418 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> 12444 T2419 oasc.ZkController.register We are http://127.0.0.1:42169/collection1/ and leader is http://127.0.0.1:42169/collection1/
[junit4:junit4] 2> 12444 T2419 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42169
[junit4:junit4] 2> 12444 T2419 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 12444 T2419 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 12445 T2419 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 12446 T2419 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 12447 T2360 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 12448 T2360 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 12448 T2360 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 12504 T2360 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 12509 T2360 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:४४८७१
[junit4:junit4] 2> 12510 T2360 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 12511 T2360 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 12511 T2360 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362795547208
[junit4:junit4] 2> 12512 T2360 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362795547208/solr.xml
[junit4:junit4] 2> 12512 T2360 oasc.CoreContainer.<init> New CoreContainer 1470249227
[junit4:junit4] 2> 12513 T2360 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362795547208/'
[junit4:junit4] 2> 12513 T2360 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362795547208/'
[junit4:junit4] 2> 12533 T2360 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 12534 T2360 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 12534 T2360 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 12534 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 12535 T2360 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 12535 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 12535 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 12535 T2360 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 12536 T2360 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 12536 T2360 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 12541 T2360 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 12549 T2360 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:52788/solr
[junit4:junit4] 2> 12550 T2360 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 12550 T2360 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52788 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@30ae76ee
[junit4:junit4] 2> 12551 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 12551 T2431 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:52788. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 12552 T2431 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:52788, initiating session
[junit4:junit4] 2> 12552 T2362 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50662
[junit4:junit4] 2> 12552 T2362 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50662
[junit4:junit4] 2> 12553 T2364 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4cf199ac0009 with negotiated timeout 20000 for client /127.0.0.1:50662
[junit4:junit4] 2> 12553 T2431 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:52788, sessionid = 0x13d4cf199ac0009, negotiated timeout = 20000
[junit4:junit4] 2> 12553 T2432 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@30ae76ee name:ZooKeeperConnection Watcher:127.0.0.1:52788 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 12553 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 12555 T2365 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4cf199ac0009
[junit4:junit4] 2> 12556 T2432 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 12556 T2362 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50662 which had sessionid 0x13d4cf199ac0009
[junit4:junit4] 2> 12555 T2360 oaz.ZooKeeper.close Session: 0x13d4cf199ac0009 closed
[junit4:junit4] 2> 12556 T2360 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 12559 T2360 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52788/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@635ab437
[junit4:junit4] 2> 12560 T2433 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:52788. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 12560 T2433 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:52788, initiating session
[junit4:junit4] 2> 12560 T2362 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50663
[junit4:junit4] 2> 12560 T2362 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50663
[junit4:junit4] 2> 12560 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 12561 T2364 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4cf199ac000a with negotiated timeout 20000 for client /127.0.0.1:50663
[junit4:junit4] 2> 12561 T2433 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:52788, sessionid = 0x13d4cf199ac000a, negotiated timeout = 20000
[junit4:junit4] 2> 12561 T2434 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@635ab437 name:ZooKeeperConnection Watcher:127.0.0.1:52788/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 12561 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 12562 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac000a type:create cxid:0x1 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 12563 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac000a type:create cxid:0x2 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 12564 T2360 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 13566 T2360 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44871_
[junit4:junit4] 2> 13567 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac000a type:delete cxid:0xb zxid:0x92 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:44871_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:44871_
[junit4:junit4] 2> 13568 T2360 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44871_
[junit4:junit4] 2> 13570 T2418 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> 13570 T2402 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> 13571 T2389 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13571 T2434 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13571 T2382 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13571 T2382 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> 13571 T2389 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> 13583 T2418 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13583 T2402 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13587 T2435 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362795547208/collection1
[junit4:junit4] 2> 13587 T2435 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 13587 T2435 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 13588 T2435 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 13588 T2435 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362795547208/collection1/'
[junit4:junit4] 2> 13589 T2435 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362795547208/collection1/lib/README' to classloader
[junit4:junit4] 2> 13589 T2435 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362795547208/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 13609 T2435 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 13635 T2435 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 13636 T2435 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 13639 T2435 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 13916 T2383 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13916 T2383 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42169",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:42169_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"active"}
[junit4:junit4] 2> 13919 T2402 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> 13919 T2382 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> 13919 T2389 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> 13919 T2434 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> 13919 T2418 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> 13941 T2435 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 13946 T2435 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 13948 T2435 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 13958 T2435 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 13961 T2435 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 13964 T2435 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 13965 T2435 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 13965 T2435 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 13965 T2435 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 13966 T2435 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 13966 T2435 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 13966 T2435 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362795547208/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty3/
[junit4:junit4] 2> 13966 T2435 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@287492a0
[junit4:junit4] 2> 13967 T2435 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 13967 T2435 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty3 forceNew: false
[junit4:junit4] 2> 13967 T2435 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty3/index/
[junit4:junit4] 2> 13968 T2435 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 13968 T2435 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty3/index forceNew: false
[junit4:junit4] 2> 13969 T2435 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@566075d0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@712d6e9c),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 13969 T2435 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 13970 T2435 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 13971 T2435 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 13971 T2435 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 13971 T2435 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 13972 T2435 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 13972 T2435 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 13972 T2435 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 13972 T2435 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 13973 T2435 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 13975 T2435 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 13977 T2435 oass.SolrIndexSearcher.<init> Opening Searcher@c4047c9 main
[junit4:junit4] 2> 13977 T2435 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty3/tlog
[junit4:junit4] 2> 13977 T2435 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 13977 T2435 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 13981 T2436 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c4047c9 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 13983 T2435 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 13983 T2435 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 15423 T2383 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 15424 T2383 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44871",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:44871_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"down"}
[junit4:junit4] 2> 15424 T2383 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 15424 T2383 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 15429 T2402 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> 15429 T2418 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> 15429 T2382 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> 15429 T2434 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> 15430 T2389 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> 15984 T2435 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 15984 T2435 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:44871 collection:collection1 shard:shard2
[junit4:junit4] 2> 15988 T2435 oasc.ZkController.register We are http://127.0.0.1:44871/collection1/ and leader is http://127.0.0.1:54255/collection1/
[junit4:junit4] 2> 15988 T2435 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44871
[junit4:junit4] 2> 15988 T2435 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 15988 T2435 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C410 name=collection1 org.apache.solr.core.SolrCore@5eff546c url=http://127.0.0.1:44871/collection1 node=127.0.0.1:44871_ C410_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:44871, core=collection1, collection=collection1, node_name=127.0.0.1:44871_, state=down}
[junit4:junit4] 2> 15989 T2437 C410 P44871 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 15989 T2435 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 15989 T2437 C410 P44871 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 15989 T2437 C410 P44871 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 15989 T2437 C410 P44871 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 15990 T2360 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 15990 T2437 C410 P44871 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 15990 T2360 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 15991 T2360 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 15996 T2360 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 15997 T2360 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 16001 T2398 oasc.CoreContainer.create Creating SolrCore 'onenodecollectioncore' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362795538155/onenodecollectioncore
[junit4:junit4] 2> 16001 T2398 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4] 2> 16001 T2398 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4] 2> 16002 T2398 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 16003 T2398 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 16003 T2398 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4] 2> 16005 T2398 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4] 2> 16006 T2398 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362795538155/onenodecollectioncore/'
[junit4:junit4] 2> 16046 T2398 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 16072 T2398 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 16073 T2398 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 16076 T2398 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 16399 T2398 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 16404 T2398 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 16406 T2398 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 16418 T2398 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 16421 T2398 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 16424 T2398 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 16425 T2398 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 16426 T2398 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 16426 T2398 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 16427 T2398 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 16427 T2398 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 16428 T2398 oasc.SolrCore.<init> [onenodecollectioncore] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362795538155/onenodecollectioncore/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362795534761/onenodecollection/
[junit4:junit4] 2> 16428 T2398 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@287492a0
[junit4:junit4] 2> 16428 T2398 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 16429 T2398 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362795534761/onenodecollection forceNew: false
[junit4:junit4] 2> 16429 T2398 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362795534761/onenodecollection/index/
[junit4:junit4] 2> 16429 T2398 oasc.SolrCore.initIndex WARNING [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362795534761/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 16430 T2398 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362795534761/onenodecollection/index forceNew: false
[junit4:junit4] 2> 16431 T2398 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@6a80afbc lockFactory=org.apache.lucene.store.NativeFSLockFactory@35a36787),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 16431 T2398 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 16432 T2398 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 16433 T2398 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 16433 T2398 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 16434 T2398 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 16434 T2398 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 16434 T2398 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 16434 T2398 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 16435 T2398 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 16435 T2398 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 16437 T2398 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 16439 T2398 oass.SolrIndexSearcher.<init> Opening Searcher@433b7ea6 main
[junit4:junit4] 2> 16440 T2398 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362795534761/onenodecollection/tlog
[junit4:junit4] 2> 16440 T2398 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 16440 T2398 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 16443 T2439 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@433b7ea6 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 16444 T2398 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> 16933 T2383 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 16934 T2383 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44871",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:44871_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"recovering"}
[junit4:junit4] 2> 16936 T2383 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:54255",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"onenodecollectioncore",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "node_name":"127.0.0.1:54255_",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"down"}
[junit4:junit4] 2> 16936 T2383 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4] 2> 16937 T2383 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 16939 T2382 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> 16939 T2389 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> 16939 T2402 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> 16939 T2418 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> 16939 T2434 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> 16997 T2396 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {core=collection1&wt=javabin&checkLive=true&coreNodeName=127.0.0.1:44871__collection1&onlyIfLeader=true&nodeName=127.0.0.1:44871_&action=PREPRECOVERY&version=2&state=recovering} status=0 QTime=1000
[junit4:junit4] 2> 17446 T2398 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4] 2> 17447 T2398 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:54255 collection:onenodecollection shard:shard1
[junit4:junit4] 2> 17448 T2398 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4] 2> 17453 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0006 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> 17454 T2398 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 17454 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0006 type:create cxid:0xa2 zxid:0xae txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 17456 T2398 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 17456 T2398 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 17457 T2398 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54255/onenodecollectioncore/
[junit4:junit4] 2> 17457 T2398 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 17457 T2398 oasc.SyncStrategy.syncToMe http://127.0.0.1:54255/onenodecollectioncore/ has no replicas
[junit4:junit4] 2> 17458 T2398 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54255/onenodecollectioncore/
[junit4:junit4] 2> 17458 T2398 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4] 2> 17461 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0006 type:create cxid:0xac zxid:0xb2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 18444 T2383 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 18450 T2402 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> 18450 T2418 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> 18450 T2382 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> 18450 T2434 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> 18450 T2389 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> 18465 T2398 oasc.ZkController.register We are http://127.0.0.1:54255/onenodecollectioncore/ and leader is http://127.0.0.1:54255/onenodecollectioncore/
[junit4:junit4] 2> 18465 T2398 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:54255
[junit4:junit4] 2> 18466 T2398 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 18466 T2398 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4] 2> 18468 T2398 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 18469 T2398 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {wt=javabin&dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362795534761/onenodecollection&collection=onenodecollection&name=onenodecollectioncore&roles=none&numShards=1&action=CREATE&version=2} status=0 QTime=2469
[junit4:junit4] 2> 18469 T2360 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4] 2> 18470 T2360 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> C410_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:44871, shard=shard2, core=collection1, collection=collection1, node_name=127.0.0.1:44871_, state=recovering}
[junit4:junit4] 2> 18998 T2437 C410 P44871 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:54255/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 18998 T2437 C410 P44871 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:44871 START replicas=[http://127.0.0.1:54255/collection1/] nUpdates=100
[junit4:junit4] 2> 18998 T2437 C410 P44871 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 18999 T2437 C410 P44871 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 18999 T2437 C410 P44871 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 18999 T2437 C410 P44871 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 18999 T2437 C410 P44871 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 18999 T2437 C410 P44871 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:54255/collection1/. core=collection1
[junit4:junit4] 2> 18999 T2437 C410 P44871 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C411 name=collection1 org.apache.solr.core.SolrCore@761fa06a url=http://127.0.0.1:54255/collection1 node=127.0.0.1:54255_ C411_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:54255, shard=shard2, core=collection1, collection=collection1, node_name=127.0.0.1:54255_, state=active, leader=true}
[junit4:junit4] 2> 19003 T2398 C411 P54255 REQ /get {wt=javabin&distrib=false&version=2&qt=/get&getVersions=100} status=0 QTime=0
[junit4:junit4] 2> 19005 T2395 C411 P54255 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 19006 T2395 C411 P54255 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4c704776 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6e0a958e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 19007 T2395 C411 P54255 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 19007 T2395 C411 P54255 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4c704776 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6e0a958e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4c704776 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6e0a958e),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 19007 T2395 C411 P54255 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 19008 T2395 C411 P54255 oass.SolrIndexSearcher.<init> Opening Searcher@c4484e realtime
[junit4:junit4] 2> 19008 T2395 C411 P54255 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 19008 T2395 C411 P54255 /update {wt=javabin&softCommit=false&commit=true&openSearcher=false&waitSearcher=true&version=2&commit_end_point=true} {commit=} 0 3
[junit4:junit4] 2> 19009 T2437 C410 P44871 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 19009 T2437 C410 P44871 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 19013 T2398 C411 P54255 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 19014 T2398 C411 P54255 REQ /replication {wt=javabin&version=2&qt=/replication&command=indexversion} status=0 QTime=4
[junit4:junit4] 2> 19015 T2437 C410 P44871 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 19015 T2437 C410 P44871 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 19015 T2437 C410 P44871 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 19017 T2397 C411 P54255 REQ /replication {wt=javabin&generation=2&version=2&qt=/replication&command=filelist} status=0 QTime=0
[junit4:junit4] 2> 19017 T2437 C410 P44871 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 19018 T2437 C410 P44871 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty3/index.20130309021913775 forceNew: false
[junit4:junit4] 2> 19018 T2437 C410 P44871 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@a892536 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7b23a29f; maxCacheMB=0.78515625 maxMergeSizeMB=0.3544921875)) fullCopy=false
[junit4:junit4] 2> 19020 T2395 C411 P54255 REQ /replication {wt=filestream&checksum=true&file=segments_2&generation=2&qt=/replication&command=filecontent} status=0 QTime=0
[junit4:junit4] 2> 19021 T2437 C410 P44871 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 19021 T2437 C410 P44871 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 19022 T2437 C410 P44871 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 19022 T2437 C410 P44871 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@566075d0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@712d6e9c),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@566075d0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@712d6e9c),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 19023 T2437 C410 P44871 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 19023 T2437 C410 P44871 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 19023 T2437 C410 P44871 oass.SolrIndexSearcher.<init> Opening Searcher@17e985f main
[junit4:junit4] 2> 19024 T2436 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@17e985f main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 19025 T2437 C410 P44871 oash.SnapPuller.fetchLatestIndex removing temporary index download directory files MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@a892536 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7b23a29f; maxCacheMB=0.78515625 maxMergeSizeMB=0.3544921875))
[junit4:junit4] 2> 19026 T2437 C410 P44871 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 19026 T2437 C410 P44871 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 19026 T2437 C410 P44871 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 19026 T2437 C410 P44871 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 19027 T2437 C410 P44871 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 19472 T2360 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 19954 T2383 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 19955 T2383 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:54255",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"onenodecollectioncore",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "node_name":"127.0.0.1:54255_",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"active"}
[junit4:junit4] 2> 19958 T2383 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44871",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:44871_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"active"}
[junit4:junit4] 2> 19961 T2382 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> 19961 T2434 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> 19961 T2418 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> 19961 T2389 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> 19961 T2402 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> 20473 T2360 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 20474 T2360 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4] 2> 20474 T2360 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 20501 T2414 oejs.Response.sendError WARNING Committed before 404 Can not find: /onenodecollectioncore/update
[junit4:junit4] 2> 20501 T2414 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> 20501 T2360 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52788 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@2aa1d8a4
[junit4:junit4] 2> 20503 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 20503 T2442 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:52788. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 20504 T2442 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:52788, initiating session
[junit4:junit4] 2> 20504 T2362 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50680
[junit4:junit4] 2> 20504 T2362 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50680
[junit4:junit4] 2> 20505 T2364 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4cf199ac000b with negotiated timeout 10000 for client /127.0.0.1:50680
[junit4:junit4] 2> 20505 T2442 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:52788, sessionid = 0x13d4cf199ac000b, negotiated timeout = 10000
[junit4:junit4] 2> 20505 T2443 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2aa1d8a4 name:ZooKeeperConnection Watcher:127.0.0.1:52788 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 20505 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 20539 T2365 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4cf199ac000b
[junit4:junit4] 2> 20540 T2443 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 20540 T2362 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50680 which had sessionid 0x13d4cf199ac000b
[junit4:junit4] 2> 20540 T2360 oaz.ZooKeeper.close Session: 0x13d4cf199ac000b closed
[junit4:junit4] 2> 20541 T2365 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4cf199ac0004
[junit4:junit4] 2> 20542 T2389 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 20542 T2362 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50646 which had sessionid 0x13d4cf199ac0004
[junit4:junit4] 2> 20542 T2360 oaz.ZooKeeper.close Session: 0x13d4cf199ac0004 closed
[junit4:junit4] 2> 20545 T2360 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 42911
[junit4:junit4] 2> 20545 T2360 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=901688613
[junit4:junit4] 2> 21466 T2383 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 21467 T2383 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42911",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "node_name":"127.0.0.1:42911_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core_node_name":"127.0.0.1:42911__collection1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"down"}
[junit4:junit4] 2> 21470 T2382 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> 21470 T2418 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> 21470 T2434 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> 21470 T2402 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> 22547 T2360 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 22547 T2360 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 22551 T2360 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@4b8f940e
[junit4:junit4] 2> 22554 T2360 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> 22554 T2360 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 22554 T2360 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 22555 T2360 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 22555 T2360 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 22556 T2360 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/control/data/index
[junit4:junit4] 2> 22556 T2360 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/control/data/index
[junit4:junit4] 2> 22557 T2360 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/control/data
[junit4:junit4] 2> 22557 T2360 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/control/data
[junit4:junit4] 2> 22559 T2383 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89312168166293507-127.0.0.1:42911_-n_0000000000) am no longer a leader.
[junit4:junit4] 2> 22559 T2365 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4cf199ac0003
[junit4:junit4] 2> 22560 T2418 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> 22560 T2434 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 22560 T2362 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50644 which had sessionid 0x13d4cf199ac0003
[junit4:junit4] 2> 22560 T2434 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> 22560 T2360 oaz.ZooKeeper.close Session: 0x13d4cf199ac0003 closed
[junit4:junit4] 2> 22560 T2402 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 22561 T2402 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> 22561 T2418 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 22562 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0006 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> 22563 T2402 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 22564 T2402 oasc.Overseer.start Overseer (id=89312168166293510-127.0.0.1:54255_-n_0000000001) starting
[junit4:junit4] 2> 22565 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0006 type:create cxid:0xc1 zxid:0xd0 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 22565 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0006 type:create cxid:0xc2 zxid:0xd1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 22566 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0006 type:create cxid:0xc3 zxid:0xd2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 22566 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0006 type:create cxid:0xc4 zxid:0xd3 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 22567 T2445 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 22567 T2444 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 22568 T2444 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 22569 T2444 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42911",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "node_name":"127.0.0.1:42911_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"down"}
[junit4:junit4] 2> 22572 T2418 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> 22572 T2402 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> 22572 T2434 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> 22583 T2360 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 22634 T2360 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 54255
[junit4:junit4] 2> 22635 T2360 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=21725380
[junit4:junit4] 2> 23860 T2382 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 23860 T2382 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> 23860 T2382 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 23860 T2382 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 24075 T2444 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 24076 T2444 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:54255",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:54255_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core_node_name":"127.0.0.1:54255__collection1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"down"}
[junit4:junit4] 2> 24079 T2444 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:54255",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"onenodecollectioncore",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "node_name":"127.0.0.1:54255_",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:54255__onenodecollectioncore",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"down"}
[junit4:junit4] 2> 24082 T2434 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> 24082 T2402 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> 24082 T2418 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> 25637 T2360 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 25638 T2360 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 25640 T2360 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> 25642 T2360 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@761fa06a
[junit4:junit4] 2> 25643 T2360 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> 25644 T2360 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 25644 T2360 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 25644 T2360 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 25645 T2360 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 25646 T2360 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty1
[junit4:junit4] 2> 25646 T2360 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty1
[junit4:junit4] 2> 25646 T2360 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty1/index
[junit4:junit4] 2> 25646 T2360 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty1/index
[junit4:junit4] 2> 25647 T2360 oasc.SolrCore.close [onenodecollectioncore] CLOSING SolrCore org.apache.solr.core.SolrCore@54c59739
[junit4:junit4] 2> 25649 T2360 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> 25649 T2360 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 25649 T2360 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 25650 T2360 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 25650 T2360 oasc.SolrCore.closeSearcher [onenodecollectioncore] Closing main searcher on request.
[junit4:junit4] 2> 25650 T2360 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362795534761/onenodecollection/index
[junit4:junit4] 2> 25650 T2360 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362795534761/onenodecollection/index
[junit4:junit4] 2> 25651 T2360 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362795534761/onenodecollection
[junit4:junit4] 2> 25651 T2360 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362795534761/onenodecollection
[junit4:junit4] 2> 25652 T2444 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89312168166293510-127.0.0.1:54255_-n_0000000001) am no longer a leader.
[junit4:junit4] 2> 25652 T2365 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4cf199ac0006
[junit4:junit4] 2> 25654 T2362 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50648 which had sessionid 0x13d4cf199ac0006
[junit4:junit4] 2> 25654 T2360 oaz.ZooKeeper.close Session: 0x13d4cf199ac0006 closed
[junit4:junit4] 2> 25654 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac000a 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> 25654 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0008 type:delete cxid:0x71 zxid:0xe5 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4] 2> 25655 T2434 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 25655 T2418 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 25655 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac000a type:create cxid:0x56 zxid:0xe6 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 25656 T2434 oasc.ShardLeaderElectionContext.shouldIBeLeader Checking if I should try and be the leader.
[junit4:junit4] 2> 25656 T2434 oasc.ShardLeaderElectionContext.shouldIBeLeader My last published State was Active, it's okay to be the leader.
[junit4:junit4] 2> 25656 T2434 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 25656 T2434 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:44871/collection1/
[junit4:junit4] 2> 25657 T2418 oasc.Overseer.start Overseer (id=89312168166293512-127.0.0.1:42169_-n_0000000002) starting
[junit4:junit4] 2> 25657 T2434 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:44871 START replicas=[http://127.0.0.1:54255/collection1/] nUpdates=100
[junit4:junit4] 2> 25657 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0008 type:create cxid:0x76 zxid:0xe9 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 25657 T2434 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:44871 DONE. We have no versions. sync failed.
[junit4:junit4] 2> 25657 T2434 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 25657 T2434 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> 25657 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0008 type:create cxid:0x77 zxid:0xea txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 25658 T2434 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:44871/collection1/
[junit4:junit4] 2> 25658 T2434 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 25658 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0008 type:create cxid:0x78 zxid:0xeb txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 25659 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac0008 type:create cxid:0x79 zxid:0xec txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 25659 T2448 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 25660 T2418 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 25660 T2418 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> 25661 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac000a type:create cxid:0x5e zxid:0xee txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 25661 T2447 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 25662 T2434 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> 25663 T2447 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 25664 T2434 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 25664 T2447 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:54255",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:54255_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"down"}
[junit4:junit4] 2> 25667 T2447 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:54255",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"onenodecollectioncore",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "node_name":"127.0.0.1:54255_",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"down"}
[junit4:junit4] 2> 25674 T2418 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> 25674 T2434 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> 25680 T2360 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 25732 T2360 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 42169
[junit4:junit4] 2> 25732 T2360 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1074483858
[junit4:junit4] 2> 26734 T2360 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 26735 T2360 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 26738 T2360 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@4b3b6e0a
[junit4:junit4] 2> 26740 T2360 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> 26741 T2360 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 26741 T2360 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 26741 T2360 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 26742 T2360 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 26742 T2360 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty2/index
[junit4:junit4] 2> 26742 T2360 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty2/index
[junit4:junit4] 2> 26743 T2360 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty2
[junit4:junit4] 2> 26743 T2360 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty2
[junit4:junit4] 2> 26744 T2447 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89312168166293512-127.0.0.1:42169_-n_0000000002) am no longer a leader.
[junit4:junit4] 2> 26745 T2365 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4cf199ac0008
[junit4:junit4] 2> 26746 T2362 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50661 which had sessionid 0x13d4cf199ac0008
[junit4:junit4] 2> 26746 T2360 oaz.ZooKeeper.close Session: 0x13d4cf199ac0008 closed
[junit4:junit4] 2> 26747 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac000a 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> 26747 T2434 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 26748 T2434 oasc.Overseer.start Overseer (id=89312168166293514-127.0.0.1:44871_-n_0000000003) starting
[junit4:junit4] 2> 26749 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac000a type:create cxid:0x6b zxid:0x102 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 26749 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac000a type:create cxid:0x6c zxid:0x103 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 26750 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac000a type:create cxid:0x6d zxid:0x104 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 26750 T2365 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4cf199ac000a type:create cxid:0x6e zxid:0x105 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 26751 T2450 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 26751 T2434 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4:junit4] 2> 26751 T2434 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> 26752 T2449 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 26753 T2449 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 26753 T2449 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42169",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:42169_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core_node_name":"127.0.0.1:42169__collection1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"down"}
[junit4:junit4] 2> 26756 T2449 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42169",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:42169_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "state":"down"}
[junit4:junit4] 2> 26758 T2434 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> 26768 T2360 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 26821 T2360 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 44871
[junit4:junit4] 2> 26821 T2360 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1470249227
[junit4:junit4] 2> 26954 T2402 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 26954 T2402 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> 26954 T2402 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 26954 T2402 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 27823 T2360 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 27823 T2360 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 27826 T2360 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@5eff546c
[junit4:junit4] 2> 27831 T2360 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> 27832 T2360 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 27832 T2360 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 27832 T2360 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 27834 T2360 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 27834 T2360 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty3/index.20130309021913775
[junit4:junit4] 2> 27835 T2360 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty3/index.20130309021913775
[junit4:junit4] 2> 27835 T2360 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty3/index
[junit4:junit4] 2> 27835 T2360 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty3/index
[junit4:junit4] 2> 27836 T2360 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty3
[junit4:junit4] 2> 27836 T2360 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362795534761/jetty3
[junit4:junit4] 2> 27837 T2449 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89312168166293514-127.0.0.1:44871_-n_0000000003) am no longer a leader.
[junit4:junit4] 2> 27837 T2365 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4cf199ac000a
[junit4:junit4] 2> 27838 T2362 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50663 which had sessionid 0x13d4cf199ac000a
[junit4:junit4] 2> 27838 T2360 oaz.ZooKeeper.close Session: 0x13d4cf199ac000a closed
[junit4:junit4] 2> 27860 T2360 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 27918 T2360 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 27918 T2360 oazs.ZooKeeperServer.shutdown shutting down
[junit4:junit4] 2> 27919 T2360 oazs.SessionTrackerImpl.shutdown Shutting down
[junit4:junit4] 2> 27919 T2360 oazs.PrepRequestProcessor.shutdown Shutting down
[junit4:junit4] 2> 27919 T2365 oazs.PrepRequestProcessor.run PrepRequestProcessor exited loop!
[junit4:junit4] 2> 27919 T2360 oazs.SyncRequestProcessor.shutdown Shutting down
[junit4:junit4] 2> 27920 T2364 oazs.SyncRequestProcessor.run SyncRequestProcessor exited!
[junit4:junit4] 2> 27920 T2360 oazs.FinalRequestProcessor.shutdown shutdown of request processor complete
[junit4:junit4] 2> 27921 T2360 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:52788 52788
[junit4:junit4] 2> 27923 T2362 oazs.NIOServerCnxnFactory.run NIOServerCnxn factory exited run method
[junit4:junit4] 2> 27923 T2360 oazs.ZooKeeperServer.shutdown shutting down
[junit4:junit4] 2> 27924 T2360 oazs.SessionTrackerImpl.shutdown Shutting down
[junit4:junit4] 2> 27924 T2360 oazs.PrepRequestProcessor.shutdown Shutting down
[junit4:junit4] 2> 27924 T2360 oazs.SyncRequestProcessor.shutdown Shutting down
[junit4:junit4] 2> 27925 T2360 oazs.FinalRequestProcessor.shutdown shutdown of request processor complete
[junit4:junit4] 2> 28046 T2418 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 28046 T2418 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> 28046 T2418 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 28047 T2418 oaz.ClientCnxn$EventThread.run EventThread shut down
[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/live_nodes (4)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:44871_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:42169_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:54255_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:42911_ (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/overseer_elect (2)
[junit4:junit4] 1> /solr/overseer_elect/leader (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"id":"89312168166293507-127.0.0.1:42911_-n_0000000000"}
[junit4:junit4] 1> /solr/overseer_elect/election (4)
[junit4:junit4] 1> /solr/overseer_elect/election/89312168166293512-127.0.0.1:42169_-n_0000000002 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89312168166293510-127.0.0.1:54255_-n_0000000001 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89312168166293514-127.0.0.1:44871_-n_0000000003 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89312168166293507-127.0.0.1:42911_-n_0000000000 (0)
[junit4:junit4] 1> /solr/clusterstate.json (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "collection1":{
[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:54255__collection1":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:54255",
[junit4:junit4] 1> "shard":"shard2",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "node_name":"127.0.0.1:54255_",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "leader":"true"},
[junit4:junit4] 1> "127.0.0.1:44871__collection1":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:44871",
[junit4:junit4] 1> "shard":"shard2",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "node_name":"127.0.0.1:44871_",
[junit4:junit4] 1> "state":"active"}}},
[junit4:junit4] 1> "shard1":{
[junit4:junit4] 1> "range":"80000000-ffffffff",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "replicas":{"127.0.0.1:42169__collection1":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:42169",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "node_name":"127.0.0.1:42169_",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "leader":"true"}}}},
[junit4:junit4] 1> "router":"compositeId"},
[junit4:junit4] 1> "onenodecollection":{
[junit4:junit4] 1> "shards":{"shard1":{
[junit4:junit4] 1> "range":"80000000-7fffffff",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "replicas":{"127.0.0.1:54255__onenodecollectioncore":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:54255",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "core":"onenodecollectioncore",
[junit4:junit4] 1> "collection":"onenodecollection",
[junit4:junit4] 1> "node_name":"127.0.0.1:54255_",
[junit4:junit4] 1> "roles":"none",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "leader":"true"}}}},
[junit4:junit4] 1> "router":"compositeId"},
[junit4:junit4] 1> "control_collection":{
[junit4:junit4] 1> "shards":{"shard1":{
[junit4:junit4] 1> "range":"80000000-7fffffff",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "replicas":{"127.0.0.1:42911__collection1":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:42911",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "collection":"control_collection",
[junit4:junit4] 1> "node_name":"127.0.0.1:42911_",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "leader":"true"}}}},
[junit4:junit4] 1> "router":"compositeId"}}
[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/leader_elect (2)
[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/89312168166293514-127.0.0.1:44871__collection1-n_0000000001 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2/election/89312168166293510-127.0.0.1:54255__collection1-n_0000000000 (0)
[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/89312168166293512-127.0.0.1:42169__collection1-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/collection1/shards (0)
[junit4:junit4] 1> /solr/collections/collection1/leaders (2)
[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:54255",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "node_name":"127.0.0.1:54255_"}
[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:42169",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "node_name":"127.0.0.1:42169_"}
[junit4:junit4] 1> /solr/collections/control_collection (3)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"configName":"conf1"}
[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/89312168166293507-127.0.0.1:42911__collection1-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/control_collection/shards (0)
[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:42911",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "node_name":"127.0.0.1:42911_"}
[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/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/89312168166293510-127.0.0.1:54255__onenodecollectioncore-n_0000000000 (0)
[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:54255",
[junit4:junit4] 1> "core":"onenodecollectioncore",
[junit4:junit4] 1> "node_name":"127.0.0.1:54255_"}
[junit4:junit4] 1> /solr/aliases.json (0)
[junit4:junit4] 1> /solr/configs (1)
[junit4:junit4] 1> /solr/configs/conf1 (9)
[junit4:junit4] 1> /solr/configs/conf1/solrconfig.xml (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/currency.xml (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/stopwords.txt (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/old_synonyms.txt (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/mapping-ISOLatin1Accent.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/configs/conf1/schema.xml (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/open-exchange-rates.json (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "disclaimer": "This data is not real, it was synthetically created to match currency.xml. It is modeled after the data format available from openexchangerates.org. See https://openexchangerates.org/documentation for details",
[junit4:junit4] 1> "license": "http://www.apache.org/licenses/LICENSE-2.0",
[junit4:junit4] 1> "timestamp": 1332070464,
[junit4:junit4] 1>
[junit4:junit4] 1>
[junit4:junit4] 1> "IMPORTANT NOTE": "In order for tests to work, this data must be kept in sync with ./currency.xml",
[junit4:junit4] 1>
[junit4:junit4] 1>
[junit4:junit4] 1> "base": "USD",
[junit4:junit4] 1> "rates": {
[junit4:junit4] 1> "USD": 1,
[junit4:junit4] 1> "JPY": 81.29,
[junit4:junit4] 1> "EUR": 2.5,
[junit4:junit4] 1> "GBP": 0.5,
[junit4:junit4] 1> "MXN": 2.0
[junit4:junit4] 1> }
[junit4:junit4] 1> }
[junit4:junit4] 1>
[junit4:junit4] 1> /zookeeper (1)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1>
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZk2Test -Dtests.method=testDistribSearch -Dtests.seed=F53F4F2F50EDCCEC -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=hi_IN -Dtests.timezone=Atlantic/Madeira -Dtests.file.encoding=UTF-8
[junit4:junit4] ERROR 28.2s J1 | BasicDistributedZk2Test.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.common.SolrException: Server at http://127.0.0.1:42169/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([F53F4F2F50EDCCEC:74D9C13727B2ACD0]:0)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:375)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
[junit4:junit4] > at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
[junit4:junit4] > at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
[junit4:junit4] > at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
[junit4:junit4] > at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:200)
[junit4:junit4] > at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:89)
[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> 28154 T2360 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 28158 T2359 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4] 2> 28244 T2363 oazs.SessionTrackerImpl.run SessionTrackerImpl exited loop!
[junit4:junit4] 2> 29138 T2434 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 29138 T2434 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> 29138 T2434 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 29139 T2434 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=hi_IN, timezone=Atlantic/Madeira
[junit4:junit4] 2> NOTE: Linux 3.2.0-38-generic amd64/Oracle Corporation 1.8.0-ea (64-bit)/cpus=8,threads=2,free=50587016,total=185733120
[junit4:junit4] 2> NOTE: All tests run in this JVM: [SolrPluginUtilsTest, PathHierarchyTokenizerFactoryTest, TestBM25SimilarityFactory, TestIndexSearcher, SignatureUpdateProcessorFactoryTest, ChaosMonkeySafeLeaderTest, DebugComponentTest, TestHashPartitioner, CurrencyFieldXmlFileTest, DocumentAnalysisRequestHandlerTest, TestNumberUtils, TestOmitPositions, DisMaxRequestHandlerTest, ShardRoutingCustomTest, JSONWriterTest, ClusterStateTest, TestWordDelimiterFilterFactory, HighlighterConfigTest, IndexReaderFactoryTest, XmlUpdateRequestHandlerTest, DOMUtilTest, TestSolrDiscoveryProperties, DirectUpdateHandlerTest, CurrencyFieldOpenExchangeTest, RequestHandlersTest, URLClassifyProcessorTest, FullSolrCloudDistribCmdsTest, DateMathParserTest, SolrCoreCheckLockOnStartupTest, TestArbitraryIndexDir, CollectionsAPIDistributedZkTest, TestJmxMonitoredMap, BasicZkTest, SolrCmdDistributorTest, TestLMJelinekMercerSimilarityFactory, MultiTermTest, PingRequestHandlerTest, TestRangeQuery, CoreContainerCoreInitFailuresTest, TestDynamicFieldCollectionResource, SuggesterTSTTest, TestPostingsSolrHighlighter, OpenCloseCoreStressTest, TestStressReorder, SpellCheckCollatorTest, TestCodecSupport, TestBinaryResponseWriter, TestElisionMultitermQuery, TestAnalyzedSuggestions, IndexBasedSpellCheckerTest, UpdateParamsTest, TestQueryTypes, ConvertedLegacyTest, TestRTGBase, DocValuesMultiTest, TestComponentsName, FieldAnalysisRequestHandlerTest, HardAutoCommitTest, UniqFieldsUpdateProcessorFactoryTest, DistanceFunctionTest, SpellCheckComponentTest, NumericFieldsTest, BadIndexSchemaTest, TestFieldTypeCollectionResource, TestSolrJ, BasicDistributedZk2Test]
[junit4:junit4] Completed on J1 in 29.18s, 1 test, 1 error <<< FAILURES!
[...truncated 436 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:381: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:361: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:183: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:449: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1213: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:877: There were test failures: 269 suites, 1137 tests, 1 error, 13 ignored (7 assumptions)
Total time: 42 minutes 29 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 64bit/jdk1.8.0-ea-b79 -XX:+UseSerialGC
Email was triggered for: Failure
Sending email for trigger: Failure