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/05 05:06:34 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/ibm-j9-jdk6) - Build # 4544
- Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/4544/
Java: 32bit/ibm-j9-jdk6
1 tests failed.
REGRESSION: org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch
Error Message:
Server at http://127.0.0.1:43455/gd_i/b/onenodecollectioncore returned non ok status:404, message:Can not find: /gd_i/b/onenodecollectioncore/update
Stack Trace:
org.apache.solr.common.SolrException: Server at http://127.0.0.1:43455/gd_i/b/onenodecollectioncore returned non ok status:404, message:Can not find: /gd_i/b/onenodecollectioncore/update
at __randomizedtesting.SeedInfo.seed([631377AFE3CEB59:87D7B96289638B65]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:373)
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:196)
at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:85)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
at java.lang.reflect.Method.invoke(Method.java:611)
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:738)
Build Log:
[...truncated 8713 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4] 2> 0 T1446 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /gd_i/b
[junit4:junit4] 2> 3 T1446 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362455837660
[junit4:junit4] 2> 4 T1446 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 5 T1447 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 7 T1447 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4] 2> 7 T1447 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4] 2> 7 T1447 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4] 2> 8 T1447 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> 9 T1447 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4] 2> 105 T1446 oasc.ZkTestServer.run start zk server on port:55158
[junit4:junit4] 2> 107 T1446 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55158 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@4de14de1
[junit4:junit4] 2> 109 T1446 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 110 T1452 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:55158. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 111 T1452 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:55158, initiating session
[junit4:junit4] 2> 111 T1448 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33265
[junit4:junit4] 2> 113 T1448 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33265
[junit4:junit4] 2> 114 T1450 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4] 2> 284 T1450 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d38b23be10000 with negotiated timeout 10000 for client /127.0.0.1:33265
[junit4:junit4] 2> 284 T1452 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:55158, sessionid = 0x13d38b23be10000, negotiated timeout = 10000
[junit4:junit4] 2> 286 T1453 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4de14de1 name:ZooKeeperConnection Watcher:127.0.0.1:55158 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 287 T1446 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 288 T1446 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 296 T1451 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d38b23be10000
[junit4:junit4] 2> 297 T1448 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33265 which had sessionid 0x13d38b23be10000
[junit4:junit4] 2> 297 T1453 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 297 T1446 oaz.ZooKeeper.close Session: 0x13d38b23be10000 closed
[junit4:junit4] 2> 300 T1446 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55158/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@58ff58ff
[junit4:junit4] 2> 302 T1446 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 303 T1454 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:55158. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 305 T1454 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:55158, initiating session
[junit4:junit4] 2> 305 T1448 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33266
[junit4:junit4] 2> 307 T1448 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33266
[junit4:junit4] 2> 309 T1450 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d38b23be10001 with negotiated timeout 10000 for client /127.0.0.1:33266
[junit4:junit4] 2> 309 T1454 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:55158, sessionid = 0x13d38b23be10001, negotiated timeout = 10000
[junit4:junit4] 2> 311 T1455 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58ff58ff name:ZooKeeperConnection Watcher:127.0.0.1:55158/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 312 T1446 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 313 T1446 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 322 T1446 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 330 T1446 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 379 T1446 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 384 T1446 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 385 T1446 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 391 T1446 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 392 T1446 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 397 T1446 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 398 T1446 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 402 T1446 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 403 T1446 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 407 T1446 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 408 T1446 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 522 T1446 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 523 T1446 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 528 T1446 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 529 T1446 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 534 T1446 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 535 T1446 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 539 T1446 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 540 T1446 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 544 T1451 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d38b23be10001
[junit4:junit4] 2> 545 T1448 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33266 which had sessionid 0x13d38b23be10001
[junit4:junit4] 2> 545 T1455 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 545 T1446 oaz.ZooKeeper.close Session: 0x13d38b23be10001 closed
[junit4:junit4] 2> 670 T1446 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 673 T1446 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:37767
[junit4:junit4] 2> 674 T1446 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 675 T1446 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 675 T1446 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362455838202
[junit4:junit4] 2> 676 T1446 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362455838202/solr.xml
[junit4:junit4] 2> 677 T1446 oasc.CoreContainer.<init> New CoreContainer 2069527386
[junit4:junit4] 2> 677 T1446 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362455838202/'
[junit4:junit4] 2> 678 T1446 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362455838202/'
[junit4:junit4] 2> 692 T1446 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 693 T1446 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 694 T1446 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 694 T1446 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 695 T1446 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 696 T1446 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 696 T1446 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 697 T1446 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 698 T1446 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 698 T1446 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 708 T1446 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 731 T1446 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:55158/solr
[junit4:junit4] 2> 732 T1446 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 733 T1446 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55158 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@30603060
[junit4:junit4] 2> 734 T1446 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 735 T1465 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:55158. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 736 T1465 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:55158, initiating session
[junit4:junit4] 2> 736 T1448 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33267
[junit4:junit4] 2> 737 T1448 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33267
[junit4:junit4] 2> 739 T1450 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d38b23be10002 with negotiated timeout 20000 for client /127.0.0.1:33267
[junit4:junit4] 2> 739 T1465 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:55158, sessionid = 0x13d38b23be10002, negotiated timeout = 20000
[junit4:junit4] 2> 740 T1466 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@30603060 name:ZooKeeperConnection Watcher:127.0.0.1:55158 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 740 T1446 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 742 T1451 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d38b23be10002
[junit4:junit4] 2> 743 T1448 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33267 which had sessionid 0x13d38b23be10002
[junit4:junit4] 2> 743 T1466 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 743 T1446 oaz.ZooKeeper.close Session: 0x13d38b23be10002 closed
[junit4:junit4] 2> 745 T1446 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 751 T1446 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55158/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@50905090
[junit4:junit4] 2> 752 T1446 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 753 T1467 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:55158. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 754 T1467 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:55158, initiating session
[junit4:junit4] 2> 754 T1448 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33268
[junit4:junit4] 2> 755 T1448 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33268
[junit4:junit4] 2> 756 T1450 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d38b23be10003 with negotiated timeout 20000 for client /127.0.0.1:33268
[junit4:junit4] 2> 756 T1467 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:55158, sessionid = 0x13d38b23be10003, negotiated timeout = 20000
[junit4:junit4] 2> 757 T1468 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50905090 name:ZooKeeperConnection Watcher:127.0.0.1:55158/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 758 T1446 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 760 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 762 T1446 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 766 T1446 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37767_gd_i%2Fb
[junit4:junit4] 2> 767 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:37767_gd_i%2Fb Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:37767_gd_i%2Fb
[junit4:junit4] 2> 768 T1446 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37767_gd_i%2Fb
[junit4:junit4] 2> 773 T1446 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 780 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10003 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> 781 T1446 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 786 T1446 oasc.Overseer.start Overseer (id=89289905777213443-127.0.0.1:37767_gd_i%2Fb-n_0000000000) starting
[junit4:junit4] 2> 788 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 789 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 790 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 792 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 794 T1446 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 794 T1470 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 798 T1446 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 811 T1469 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 814 T1471 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362455838202/collection1
[junit4:junit4] 2> 814 T1471 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 816 T1471 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 816 T1471 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 818 T1471 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362455838202/collection1/'
[junit4:junit4] 2> 819 T1471 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362455838202/collection1/lib/README' to classloader
[junit4:junit4] 2> 820 T1471 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362455838202/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 848 T1471 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 892 T1471 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 893 T1471 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 898 T1471 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 1312 T1471 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1318 T1471 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1321 T1471 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1341 T1471 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1350 T1471 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1355 T1471 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1357 T1471 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1357 T1471 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 1358 T1471 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1360 T1471 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1360 T1471 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 1369 T1471 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362455838202/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/control/data/
[junit4:junit4] 2> 1369 T1471 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2630263
[junit4:junit4] 2> 1370 T1471 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4] 2> 1373 T1471 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/control/data forceNew:false
[junit4:junit4] 2> 1374 T1471 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/control/data
[junit4:junit4] 2> 1374 T1471 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/control/data/index/
[junit4:junit4] 2> 1375 T1471 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1376 T1471 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/control/data/index forceNew:false
[junit4:junit4] 2> 1382 T1471 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@21742174; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 1382 T1471 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 1383 T1471 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/control/data/index
[junit4:junit4] 2> 1385 T1471 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1386 T1471 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1386 T1471 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1387 T1471 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1388 T1471 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1388 T1471 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1389 T1471 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1390 T1471 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1390 T1471 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1392 T1471 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1394 T1471 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/control/data
[junit4:junit4] 2> 1395 T1471 oass.SolrIndexSearcher.<init> Opening Searcher@299a299a main
[junit4:junit4] 2> 1396 T1471 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1397 T1471 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1402 T1471 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/control/data
[junit4:junit4] 2> 1403 T1472 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@299a299a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1405 T1471 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1405 T1471 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1407 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10003 type:create cxid:0x50 zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4] 2> 2318 T1469 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2319 T1469 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:37767/gd_i/b",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:37767_gd_i%2Fb",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 2320 T1469 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 2321 T1469 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 2322 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10003 type:create cxid:0x58 zxid:0x2c txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4] 2> 2330 T1468 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> 2410 T1471 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2411 T1471 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:37767/gd_i/b collection:control_collection shard:shard1
[junit4:junit4] 2> 2414 T1471 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2454 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10003 type:delete cxid:0x72 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4] 2> 2455 T1471 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2456 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10003 type:create cxid:0x73 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 2459 T1471 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2459 T1471 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2460 T1471 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:37767/gd_i/b/collection1/
[junit4:junit4] 2> 2460 T1471 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2461 T1471 oasc.SyncStrategy.syncToMe http://127.0.0.1:37767/gd_i/b/collection1/ has no replicas
[junit4:junit4] 2> 2461 T1471 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:37767/gd_i/b/collection1/
[junit4:junit4] 2> 2462 T1471 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 2469 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10003 type:create cxid:0x7d zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3839 T1469 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3856 T1468 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> 3875 T1471 oasc.ZkController.register We are http://127.0.0.1:37767/gd_i/b/collection1/ and leader is http://127.0.0.1:37767/gd_i/b/collection1/
[junit4:junit4] 2> 3875 T1471 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:37767/gd_i/b
[junit4:junit4] 2> 3876 T1471 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 3876 T1471 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 3877 T1471 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 3880 T1471 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3881 T1446 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 3882 T1446 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 3883 T1446 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 3888 T1446 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 3889 T1446 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55158/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@16ba16ba
[junit4:junit4] 2> 3890 T1446 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3901 T1473 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:55158. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 3902 T1473 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:55158, initiating session
[junit4:junit4] 2> 3902 T1448 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33270
[junit4:junit4] 2> 3903 T1448 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33270
[junit4:junit4] 2> 3904 T1450 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d38b23be10004 with negotiated timeout 10000 for client /127.0.0.1:33270
[junit4:junit4] 2> 3904 T1473 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:55158, sessionid = 0x13d38b23be10004, negotiated timeout = 10000
[junit4:junit4] 2> 3905 T1474 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16ba16ba name:ZooKeeperConnection Watcher:127.0.0.1:55158/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3905 T1446 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3906 T1446 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 3909 T1446 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 4029 T1446 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 4031 T1446 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:33021
[junit4:junit4] 2> 4032 T1446 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 4033 T1446 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 4033 T1446 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362455841565
[junit4:junit4] 2> 4034 T1446 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362455841565/solr.xml
[junit4:junit4] 2> 4035 T1446 oasc.CoreContainer.<init> New CoreContainer 1281444961
[junit4:junit4] 2> 4035 T1446 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362455841565/'
[junit4:junit4] 2> 4036 T1446 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362455841565/'
[junit4:junit4] 2> 4059 T1446 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 4060 T1446 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 4061 T1446 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 4061 T1446 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 4062 T1446 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 4062 T1446 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 4063 T1446 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 4064 T1446 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 4064 T1446 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 4065 T1446 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 4074 T1446 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 4086 T1446 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:55158/solr
[junit4:junit4] 2> 4087 T1446 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 4087 T1446 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55158 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@58955895
[junit4:junit4] 2> 4088 T1446 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 4089 T1484 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:55158. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 4090 T1484 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:55158, initiating session
[junit4:junit4] 2> 4090 T1448 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33271
[junit4:junit4] 2> 4091 T1448 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33271
[junit4:junit4] 2> 4092 T1450 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d38b23be10005 with negotiated timeout 20000 for client /127.0.0.1:33271
[junit4:junit4] 2> 4092 T1484 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:55158, sessionid = 0x13d38b23be10005, negotiated timeout = 20000
[junit4:junit4] 2> 4093 T1485 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58955895 name:ZooKeeperConnection Watcher:127.0.0.1:55158 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 4093 T1446 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 4095 T1451 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d38b23be10005
[junit4:junit4] 2> 4096 T1448 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33271 which had sessionid 0x13d38b23be10005
[junit4:junit4] 2> 4096 T1485 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 4096 T1446 oaz.ZooKeeper.close Session: 0x13d38b23be10005 closed
[junit4:junit4] 2> 4097 T1446 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 4103 T1446 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55158/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@7210721
[junit4:junit4] 2> 4105 T1446 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 4105 T1486 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:55158. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 4106 T1486 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:55158, initiating session
[junit4:junit4] 2> 4106 T1448 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33272
[junit4:junit4] 2> 4107 T1448 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33272
[junit4:junit4] 2> 4108 T1450 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d38b23be10006 with negotiated timeout 20000 for client /127.0.0.1:33272
[junit4:junit4] 2> 4108 T1486 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:55158, sessionid = 0x13d38b23be10006, negotiated timeout = 20000
[junit4:junit4] 2> 4117 T1487 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7210721 name:ZooKeeperConnection Watcher:127.0.0.1:55158/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 4117 T1446 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 4118 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10006 type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 4120 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10006 type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 4124 T1446 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 5129 T1446 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33021_gd_i%2Fb
[junit4:junit4] 2> 5130 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10006 type:delete cxid:0x9 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:33021_gd_i%2Fb Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:33021_gd_i%2Fb
[junit4:junit4] 2> 5132 T1446 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:33021_gd_i%2Fb
[junit4:junit4] 2> 5135 T1468 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> 5136 T1474 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 5137 T1487 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 5138 T1468 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 5145 T1488 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362455841565/collection1
[junit4:junit4] 2> 5146 T1488 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 5147 T1488 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 5147 T1488 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 5149 T1488 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362455841565/collection1/'
[junit4:junit4] 2> 5150 T1488 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362455841565/collection1/lib/README' to classloader
[junit4:junit4] 2> 5151 T1488 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362455841565/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 5196 T1488 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 5231 T1488 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 5232 T1488 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 5237 T1488 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 5373 T1469 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 5375 T1469 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:37767/gd_i/b",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:37767_gd_i%2Fb",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 5382 T1468 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> 5382 T1487 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> 5382 T1474 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> 5645 T1488 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 5650 T1488 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 5653 T1488 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 5673 T1488 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 5678 T1488 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 5683 T1488 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 5685 T1488 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 5686 T1488 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 5688 T1488 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 5690 T1488 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 5691 T1488 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 5692 T1488 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362455841565/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty1/
[junit4:junit4] 2> 5701 T1488 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2630263
[junit4:junit4] 2> 5702 T1488 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4] 2> 5704 T1488 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty1 forceNew:false
[junit4:junit4] 2> 5705 T1488 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty1
[junit4:junit4] 2> 5705 T1488 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty1/index/
[junit4:junit4] 2> 5706 T1488 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 5708 T1488 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty1/index forceNew:false
[junit4:junit4] 2> 5715 T1488 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@22c522c5; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 5716 T1488 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 5717 T1488 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty1/index
[junit4:junit4] 2> 5719 T1488 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 5720 T1488 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 5720 T1488 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 5721 T1488 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 5722 T1488 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 5722 T1488 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 5723 T1488 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 5724 T1488 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 5725 T1488 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 5726 T1488 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 5729 T1488 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty1
[junit4:junit4] 2> 5731 T1488 oass.SolrIndexSearcher.<init> Opening Searcher@16181618 main
[junit4:junit4] 2> 5732 T1488 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 5733 T1488 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 5740 T1489 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@16181618 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 5744 T1488 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 5744 T1488 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 6892 T1469 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 6893 T1469 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:33021/gd_i/b",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:33021_gd_i%2Fb",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 6894 T1469 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 6894 T1469 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 6902 T1487 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> 6902 T1474 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> 6902 T1468 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> 7746 T1488 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 7747 T1488 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:33021/gd_i/b collection:collection1 shard:shard1
[junit4:junit4] 2> 7749 T1488 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 7761 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10006 type:delete cxid:0x46 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4] 2> 7762 T1488 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 7763 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10006 type:create cxid:0x47 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 7766 T1488 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 7767 T1488 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 7767 T1488 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:33021/gd_i/b/collection1/
[junit4:junit4] 2> 7768 T1488 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 7769 T1488 oasc.SyncStrategy.syncToMe http://127.0.0.1:33021/gd_i/b/collection1/ has no replicas
[junit4:junit4] 2> 7770 T1488 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:33021/gd_i/b/collection1/
[junit4:junit4] 2> 7771 T1488 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 7807 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10006 type:create cxid:0x51 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8410 T1469 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8423 T1474 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> 8423 T1468 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> 8423 T1487 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> 8461 T1488 oasc.ZkController.register We are http://127.0.0.1:33021/gd_i/b/collection1/ and leader is http://127.0.0.1:33021/gd_i/b/collection1/
[junit4:junit4] 2> 8462 T1488 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:33021/gd_i/b
[junit4:junit4] 2> 8463 T1488 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 8463 T1488 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 8464 T1488 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 8467 T1488 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8469 T1446 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 8470 T1446 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 8471 T1446 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 8605 T1446 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 8607 T1446 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:43455
[junit4:junit4] 2> 8609 T1446 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 8610 T1446 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 8611 T1446 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362455846134
[junit4:junit4] 2> 8612 T1446 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362455846134/solr.xml
[junit4:junit4] 2> 8612 T1446 oasc.CoreContainer.<init> New CoreContainer 1879404549
[junit4:junit4] 2> 8614 T1446 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362455846134/'
[junit4:junit4] 2> 8615 T1446 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362455846134/'
[junit4:junit4] 2> 8643 T1446 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 8644 T1446 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 8645 T1446 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 8646 T1446 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 8647 T1446 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 8648 T1446 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 8649 T1446 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 8650 T1446 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 8651 T1446 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 8652 T1446 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 8666 T1446 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 8681 T1446 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:55158/solr
[junit4:junit4] 2> 8682 T1446 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 8683 T1446 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55158 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@39ec39ec
[junit4:junit4] 2> 8684 T1446 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8685 T1499 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:55158. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 8685 T1499 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:55158, initiating session
[junit4:junit4] 2> 8686 T1448 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33273
[junit4:junit4] 2> 8686 T1448 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33273
[junit4:junit4] 2> 8687 T1450 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d38b23be10007 with negotiated timeout 20000 for client /127.0.0.1:33273
[junit4:junit4] 2> 8687 T1499 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:55158, sessionid = 0x13d38b23be10007, negotiated timeout = 20000
[junit4:junit4] 2> 8688 T1500 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@39ec39ec name:ZooKeeperConnection Watcher:127.0.0.1:55158 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8689 T1446 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8691 T1451 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d38b23be10007
[junit4:junit4] 2> 8692 T1448 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33273 which had sessionid 0x13d38b23be10007
[junit4:junit4] 2> 8692 T1500 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 8692 T1446 oaz.ZooKeeper.close Session: 0x13d38b23be10007 closed
[junit4:junit4] 2> 8693 T1446 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 8700 T1446 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55158/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@a520a52
[junit4:junit4] 2> 8701 T1446 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8702 T1501 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:55158. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 8703 T1501 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:55158, initiating session
[junit4:junit4] 2> 8703 T1448 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33274
[junit4:junit4] 2> 8704 T1448 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33274
[junit4:junit4] 2> 8705 T1450 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d38b23be10008 with negotiated timeout 20000 for client /127.0.0.1:33274
[junit4:junit4] 2> 8705 T1501 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:55158, sessionid = 0x13d38b23be10008, negotiated timeout = 20000
[junit4:junit4] 2> 8706 T1502 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a520a52 name:ZooKeeperConnection Watcher:127.0.0.1:55158/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8706 T1446 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8707 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10008 type:create cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8709 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10008 type:create cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8711 T1446 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 9716 T1446 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43455_gd_i%2Fb
[junit4:junit4] 2> 9717 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10008 type:delete cxid:0x9 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:43455_gd_i%2Fb Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:43455_gd_i%2Fb
[junit4:junit4] 2> 9718 T1446 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43455_gd_i%2Fb
[junit4:junit4] 2> 9722 T1468 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> 9722 T1474 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> 9723 T1487 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> 9725 T1502 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9739 T1474 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9739 T1468 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9741 T1487 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9748 T1503 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362455846134/collection1
[junit4:junit4] 2> 9748 T1503 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 9750 T1503 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 9750 T1503 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 9753 T1503 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362455846134/collection1/'
[junit4:junit4] 2> 9754 T1503 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362455846134/collection1/lib/README' to classloader
[junit4:junit4] 2> 9755 T1503 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362455846134/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 9783 T1503 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 9841 T1503 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 9843 T1503 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 9847 T1503 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 9935 T1469 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 9937 T1469 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:33021/gd_i/b",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:33021_gd_i%2Fb",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 9947 T1468 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> 9947 T1502 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> 9947 T1487 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> 9947 T1474 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> 10242 T1503 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 10247 T1503 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 10250 T1503 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 10271 T1503 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 10276 T1503 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 10281 T1503 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 10283 T1503 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 10283 T1503 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 10284 T1503 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 10286 T1503 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 10287 T1503 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 10287 T1503 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362455846134/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty2/
[junit4:junit4] 2> 10288 T1503 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2630263
[junit4:junit4] 2> 10288 T1503 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4] 2> 10289 T1503 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty2 forceNew:false
[junit4:junit4] 2> 10290 T1503 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty2
[junit4:junit4] 2> 10290 T1503 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty2/index/
[junit4:junit4] 2> 10291 T1503 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 10292 T1503 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty2/index forceNew:false
[junit4:junit4] 2> 10297 T1503 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@16311631; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 10298 T1503 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 10298 T1503 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty2/index
[junit4:junit4] 2> 10301 T1503 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 10301 T1503 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 10303 T1503 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 10304 T1503 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 10305 T1503 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 10306 T1503 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 10307 T1503 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 10309 T1503 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 10310 T1503 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 10313 T1503 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 10316 T1503 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty2
[junit4:junit4] 2> 10325 T1503 oass.SolrIndexSearcher.<init> Opening Searcher@542b542b main
[junit4:junit4] 2> 10326 T1503 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 10326 T1503 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 10333 T1504 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@542b542b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 10337 T1503 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 10337 T1503 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 11457 T1469 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 11458 T1469 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:43455/gd_i/b",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:43455_gd_i%2Fb",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 11459 T1469 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 11460 T1469 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 11471 T1468 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> 11471 T1502 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> 11472 T1487 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> 11471 T1474 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> 12340 T1503 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 12341 T1503 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:43455/gd_i/b collection:collection1 shard:shard2
[junit4:junit4] 2> 12344 T1503 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 12356 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10008 type:delete cxid:0x45 zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard2 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard2
[junit4:junit4] 2> 12357 T1503 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 12358 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10008 type:create cxid:0x46 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 12361 T1503 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 12361 T1503 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 12362 T1503 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:43455/gd_i/b/collection1/
[junit4:junit4] 2> 12362 T1503 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 12363 T1503 oasc.SyncStrategy.syncToMe http://127.0.0.1:43455/gd_i/b/collection1/ has no replicas
[junit4:junit4] 2> 12363 T1503 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:43455/gd_i/b/collection1/
[junit4:junit4] 2> 12364 T1503 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 12369 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10008 type:create cxid:0x4f zxid:0x82 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 12982 T1469 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13009 T1468 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> 13009 T1474 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> 13009 T1502 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> 13010 T1487 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> 13023 T1503 oasc.ZkController.register We are http://127.0.0.1:43455/gd_i/b/collection1/ and leader is http://127.0.0.1:43455/gd_i/b/collection1/
[junit4:junit4] 2> 13024 T1503 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:43455/gd_i/b
[junit4:junit4] 2> 13024 T1503 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 13025 T1503 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 13025 T1503 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 13028 T1503 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13030 T1446 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 13031 T1446 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 13031 T1446 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 13161 T1446 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 13163 T1446 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:39862
[junit4:junit4] 2> 13164 T1446 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 13165 T1446 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 13165 T1446 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362455850695
[junit4:junit4] 2> 13166 T1446 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362455850695/solr.xml
[junit4:junit4] 2> 13167 T1446 oasc.CoreContainer.<init> New CoreContainer 2134409016
[junit4:junit4] 2> 13168 T1446 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362455850695/'
[junit4:junit4] 2> 13168 T1446 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362455850695/'
[junit4:junit4] 2> 13191 T1446 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 13191 T1446 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 13192 T1446 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 13193 T1446 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 13193 T1446 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 13194 T1446 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 13195 T1446 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 13195 T1446 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 13196 T1446 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 13196 T1446 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 13206 T1446 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 13217 T1446 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:55158/solr
[junit4:junit4] 2> 13218 T1446 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 13219 T1446 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55158 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@5ddf5ddf
[junit4:junit4] 2> 13220 T1446 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 13221 T1514 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:55158. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 13221 T1514 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:55158, initiating session
[junit4:junit4] 2> 13222 T1448 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33275
[junit4:junit4] 2> 13222 T1448 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33275
[junit4:junit4] 2> 13224 T1450 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d38b23be10009 with negotiated timeout 20000 for client /127.0.0.1:33275
[junit4:junit4] 2> 13224 T1514 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:55158, sessionid = 0x13d38b23be10009, negotiated timeout = 20000
[junit4:junit4] 2> 13225 T1515 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ddf5ddf name:ZooKeeperConnection Watcher:127.0.0.1:55158 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 13225 T1446 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 13227 T1451 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d38b23be10009
[junit4:junit4] 2> 13228 T1448 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33275 which had sessionid 0x13d38b23be10009
[junit4:junit4] 2> 13228 T1515 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 13228 T1446 oaz.ZooKeeper.close Session: 0x13d38b23be10009 closed
[junit4:junit4] 2> 13231 T1446 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 13239 T1446 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55158/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@18ec18ec
[junit4:junit4] 2> 13240 T1446 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 13242 T1516 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:55158. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 13243 T1516 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:55158, initiating session
[junit4:junit4] 2> 13243 T1448 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33276
[junit4:junit4] 2> 13244 T1448 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33276
[junit4:junit4] 2> 13245 T1450 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d38b23be1000a with negotiated timeout 20000 for client /127.0.0.1:33276
[junit4:junit4] 2> 13245 T1516 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:55158, sessionid = 0x13d38b23be1000a, negotiated timeout = 20000
[junit4:junit4] 2> 13247 T1517 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18ec18ec name:ZooKeeperConnection Watcher:127.0.0.1:55158/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 13247 T1446 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 13249 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be1000a type:create cxid:0x1 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13250 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be1000a type:create cxid:0x2 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13253 T1446 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 14257 T1446 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39862_gd_i%2Fb
[junit4:junit4] 2> 14259 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be1000a type:delete cxid:0x9 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:39862_gd_i%2Fb Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:39862_gd_i%2Fb
[junit4:junit4] 2> 14260 T1446 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39862_gd_i%2Fb
[junit4:junit4] 2> 14264 T1468 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> 14264 T1474 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> 14264 T1502 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> 14264 T1487 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> 14266 T1517 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14294 T1468 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14294 T1474 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14295 T1487 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14295 T1502 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14303 T1518 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362455850695/collection1
[junit4:junit4] 2> 14303 T1518 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 14304 T1518 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 14305 T1518 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 14307 T1518 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362455850695/collection1/'
[junit4:junit4] 2> 14308 T1518 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362455850695/collection1/lib/README' to classloader
[junit4:junit4] 2> 14309 T1518 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362455850695/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 14339 T1518 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 14387 T1518 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 14389 T1518 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 14393 T1518 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 14532 T1469 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 14534 T1469 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:43455/gd_i/b",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:43455_gd_i%2Fb",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 14540 T1468 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> 14540 T1474 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> 14540 T1502 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> 14540 T1487 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> 14540 T1517 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> 14779 T1518 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 14784 T1518 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 14786 T1518 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 14812 T1518 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 14830 T1518 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 14837 T1518 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 14840 T1518 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 14840 T1518 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 14841 T1518 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 14843 T1518 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 14843 T1518 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 14844 T1518 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362455850695/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3/
[junit4:junit4] 2> 14845 T1518 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2630263
[junit4:junit4] 2> 14846 T1518 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4] 2> 14848 T1518 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3 forceNew:false
[junit4:junit4] 2> 14848 T1518 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3
[junit4:junit4] 2> 14849 T1518 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3/index/
[junit4:junit4] 2> 14850 T1518 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 14851 T1518 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3/index forceNew:false
[junit4:junit4] 2> 14858 T1518 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7980798; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 14859 T1518 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 14860 T1518 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3/index
[junit4:junit4] 2> 14862 T1518 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 14863 T1518 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 14863 T1518 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 14864 T1518 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 14865 T1518 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 14865 T1518 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 14866 T1518 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 14867 T1518 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 14868 T1518 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 14869 T1518 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 14871 T1518 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3
[junit4:junit4] 2> 14872 T1518 oass.SolrIndexSearcher.<init> Opening Searcher@2b8a2b8a main
[junit4:junit4] 2> 14873 T1518 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 14874 T1518 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 14883 T1519 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2b8a2b8a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 14888 T1518 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 14889 T1518 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 16049 T1469 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 16050 T1469 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:39862/gd_i/b",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:39862_gd_i%2Fb",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 16050 T1469 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 16051 T1469 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 16056 T1474 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> 16056 T1517 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> 16056 T1502 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> 16056 T1468 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> 16056 T1487 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> 16892 T1518 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 16892 T1518 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:39862/gd_i/b collection:collection1 shard:shard1
[junit4:junit4] 2> 16898 T1518 oasc.ZkController.register We are http://127.0.0.1:39862/gd_i/b/collection1/ and leader is http://127.0.0.1:33021/gd_i/b/collection1/
[junit4:junit4] 2> 16898 T1518 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39862/gd_i/b
[junit4:junit4] 2> 16898 T1518 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 16899 T1518 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C110 name=collection1 org.apache.solr.core.SolrCore@2e442e44 url=http://127.0.0.1:39862/gd_i/b/collection1 node=127.0.0.1:39862_gd_i%2Fb C110_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:39862/gd_i/b, state=down, node_name=127.0.0.1:39862_gd_i%2Fb, collection=collection1, core=collection1}
[junit4:junit4] 2> 16900 T1520 C110 P39862 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 16900 T1520 C110 P39862 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 16901 T1518 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 16901 T1520 C110 P39862 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 16902 T1520 C110 P39862 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 16903 T1446 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 16904 T1520 C110 P39862 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 16903 T1446 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 16905 T1446 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 17048 T1446 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 17050 T1446 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40647
[junit4:junit4] 2> 17051 T1446 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 17052 T1446 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 17053 T1446 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1362455854566
[junit4:junit4] 2> 17053 T1446 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1362455854566/solr.xml
[junit4:junit4] 2> 17054 T1446 oasc.CoreContainer.<init> New CoreContainer 392566630
[junit4:junit4] 2> 17055 T1446 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1362455854566/'
[junit4:junit4] 2> 17055 T1446 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1362455854566/'
[junit4:junit4] 2> 17070 T1446 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 17070 T1446 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 17071 T1446 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 17072 T1446 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 17072 T1446 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 17073 T1446 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 17073 T1446 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 17074 T1446 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 17075 T1446 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 17075 T1446 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 17084 T1446 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 17098 T1446 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:55158/solr
[junit4:junit4] 2> 17098 T1446 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 17099 T1446 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55158 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@33703370
[junit4:junit4] 2> 17100 T1446 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 17101 T1530 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:55158. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 17102 T1530 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:55158, initiating session
[junit4:junit4] 2> 17102 T1448 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33278
[junit4:junit4] 2> 17103 T1448 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33278
[junit4:junit4] 2> 17104 T1450 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d38b23be1000b with negotiated timeout 20000 for client /127.0.0.1:33278
[junit4:junit4] 2> 17104 T1530 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:55158, sessionid = 0x13d38b23be1000b, negotiated timeout = 20000
[junit4:junit4] 2> 17105 T1531 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@33703370 name:ZooKeeperConnection Watcher:127.0.0.1:55158 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 17105 T1446 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 17107 T1451 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d38b23be1000b
[junit4:junit4] 2> 17108 T1448 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33278 which had sessionid 0x13d38b23be1000b
[junit4:junit4] 2> 17108 T1531 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 17108 T1446 oaz.ZooKeeper.close Session: 0x13d38b23be1000b closed
[junit4:junit4] 2> 17109 T1446 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 17116 T1446 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55158/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@7c9c7c9c
[junit4:junit4] 2> 17117 T1446 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 17118 T1532 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:55158. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 17119 T1532 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:55158, initiating session
[junit4:junit4] 2> 17119 T1448 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33279
[junit4:junit4] 2> 17120 T1448 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33279
[junit4:junit4] 2> 17121 T1450 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d38b23be1000c with negotiated timeout 20000 for client /127.0.0.1:33279
[junit4:junit4] 2> 17121 T1532 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:55158, sessionid = 0x13d38b23be1000c, negotiated timeout = 20000
[junit4:junit4] 2> 17122 T1533 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c9c7c9c name:ZooKeeperConnection Watcher:127.0.0.1:55158/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 17122 T1446 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 17124 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be1000c type:create cxid:0x1 zxid:0xa2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 17125 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be1000c type:create cxid:0x2 zxid:0xa3 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 17128 T1446 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 17568 T1469 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 17570 T1469 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:39862/gd_i/b",
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:39862_gd_i%2Fb",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 17587 T1502 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> 17587 T1474 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> 17587 T1517 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> 17587 T1487 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> 17587 T1533 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> 17587 T1468 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> 18132 T1446 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40647_gd_i%2Fb
[junit4:junit4] 2> 18134 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be1000c type:delete cxid:0xb zxid:0xa8 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:40647_gd_i%2Fb Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:40647_gd_i%2Fb
[junit4:junit4] 2> 18135 T1446 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40647_gd_i%2Fb
[junit4:junit4] 2> 18138 T1468 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> 18138 T1474 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> 18138 T1533 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> 18139 T1502 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> 18139 T1487 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> 18138 T1517 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> 18144 T1474 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 18145 T1468 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 18148 T1502 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 18149 T1517 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 18150 T1487 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 18149 T1533 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 18160 T1534 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1362455854566/collection1
[junit4:junit4] 2> 18160 T1534 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 18162 T1534 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 18162 T1534 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 18165 T1534 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1362455854566/collection1/'
[junit4:junit4] 2> 18166 T1534 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1362455854566/collection1/lib/README' to classloader
[junit4:junit4] 2> 18166 T1534 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1362455854566/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 18206 T1534 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 18240 T1534 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 18242 T1534 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 18247 T1534 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 18641 T1534 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 18646 T1534 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 18649 T1534 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 18687 T1534 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 18692 T1534 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 18697 T1534 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 18700 T1534 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 18700 T1534 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 18701 T1534 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 18703 T1534 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 18704 T1534 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 18704 T1534 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1362455854566/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4/
[junit4:junit4] 2> 18705 T1534 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2630263
[junit4:junit4] 2> 18706 T1534 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4] 2> 18707 T1534 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4 forceNew:false
[junit4:junit4] 2> 18707 T1534 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4
[junit4:junit4] 2> 18708 T1534 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4/index/
[junit4:junit4] 2> 18708 T1534 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 18709 T1534 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4/index forceNew:false
[junit4:junit4] 2> 18714 T1534 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2b152b15; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 18715 T1534 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 18716 T1534 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4/index
[junit4:junit4] 2> 18718 T1534 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 18719 T1534 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 18720 T1534 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 18720 T1534 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 18721 T1534 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 18722 T1534 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 18722 T1534 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 18723 T1534 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 18724 T1534 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 18725 T1534 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 18727 T1534 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4
[junit4:junit4] 2> 18729 T1534 oass.SolrIndexSearcher.<init> Opening Searcher@692e692e main
[junit4:junit4] 2> 18730 T1534 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 18730 T1534 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 18737 T1535 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@692e692e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 18741 T1534 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 18741 T1534 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 19096 T1469 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 19098 T1469 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:40647/gd_i/b",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:40647_gd_i%2Fb",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 19099 T1469 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 19099 T1469 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 19106 T1468 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 19106 T1517 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 19106 T1533 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 19106 T1474 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 19106 T1502 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 19106 T1487 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 19743 T1534 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 19744 T1534 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:40647/gd_i/b collection:collection1 shard:shard2
[junit4:junit4] 2> 19753 T1534 oasc.ZkController.register We are http://127.0.0.1:40647/gd_i/b/collection1/ and leader is http://127.0.0.1:43455/gd_i/b/collection1/
[junit4:junit4] 2> 19754 T1534 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:40647/gd_i/b
[junit4:junit4] 2> 19755 T1534 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 19755 T1534 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C111 name=collection1 org.apache.solr.core.SolrCore@1830183 url=http://127.0.0.1:40647/gd_i/b/collection1 node=127.0.0.1:40647_gd_i%2Fb C111_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:40647/gd_i/b, state=down, node_name=127.0.0.1:40647_gd_i%2Fb, collection=collection1, core=collection1}
[junit4:junit4] 2> 19756 T1536 C111 P40647 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 19757 T1536 C111 P40647 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 19757 T1534 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 19758 T1536 C111 P40647 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 19759 T1536 C111 P40647 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 19760 T1446 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 19761 T1536 C111 P40647 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 19761 T1446 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 19762 T1446 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 19768 T1446 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 19770 T1446 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 19779 T1482 oasc.CoreContainer.create Creating SolrCore 'onenodecollectioncore' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362455841565/onenodecollectioncore
[junit4:junit4] 2> 19780 T1482 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4] 2> 19782 T1482 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4] 2> 19782 T1482 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 19785 T1482 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 19786 T1482 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4] 2> 19790 T1482 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4] 2> 19792 T1482 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362455841565/onenodecollectioncore/'
[junit4:junit4] 2> 19833 T1482 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 19867 T1482 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 19869 T1482 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 19874 T1482 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> C110_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:39862/gd_i/b, state=recovering, node_name=127.0.0.1:39862_gd_i%2Fb, collection=collection1, shard=shard1, core=collection1}
[junit4:junit4] 2> 19936 T1520 C110 P39862 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:33021/gd_i/b/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 19936 T1520 C110 P39862 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:39862/gd_i/b START replicas=[http://127.0.0.1:33021/gd_i/b/collection1/] nUpdates=100
[junit4:junit4] 2> 19937 T1520 C110 P39862 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 19938 T1520 C110 P39862 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 19938 T1520 C110 P39862 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 19939 T1520 C110 P39862 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 19940 T1520 C110 P39862 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 19940 T1520 C110 P39862 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:33021/gd_i/b/collection1/. core=collection1
[junit4:junit4] 2> 19941 T1520 C110 P39862 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C112 name=collection1 org.apache.solr.core.SolrCore@41324132 url=http://127.0.0.1:33021/gd_i/b/collection1 node=127.0.0.1:33021_gd_i%2Fb C112_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:33021/gd_i/b, state=active, node_name=127.0.0.1:33021_gd_i%2Fb, collection=collection1, shard=shard1, core=collection1, leader=true}
[junit4:junit4] 2> 19941 T1483 C112 P33021 REQ /get {getVersions=100&qt=/get&distrib=false&version=2&wt=javabin} status=0 QTime=0
[junit4:junit4] 2> 19960 T1481 C112 P33021 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 19961 T1481 C112 P33021 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty1
[junit4:junit4] 2> 19965 T1481 C112 P33021 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@22c522c5; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 19966 T1481 C112 P33021 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 19980 T1481 C112 P33021 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@22c522c5; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@22c522c5; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 19982 T1481 C112 P33021 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 19983 T1481 C112 P33021 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty1
[junit4:junit4] 2> 19984 T1481 C112 P33021 oass.SolrIndexSearcher.<init> Opening Searcher@4c174c17 realtime
[junit4:junit4] 2> 19986 T1481 C112 P33021 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 19986 T1481 C112 P33021 /update {softCommit=false&commit_end_point=true&commit=true&version=2&waitSearcher=true&wt=javabin&openSearcher=false} {commit=} 0 26
[junit4:junit4] 2> 19988 T1520 C110 P39862 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 19988 T1520 C110 P39862 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 19990 T1483 C112 P33021 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 19991 T1483 C112 P33021 REQ /replication {qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 19992 T1520 C110 P39862 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 19992 T1520 C110 P39862 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 19992 T1520 C110 P39862 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 19994 T1481 C112 P33021 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty1
[junit4:junit4] 2> 19996 T1481 C112 P33021 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty1/index
[junit4:junit4] 2> 19996 T1481 C112 P33021 REQ /replication {qt=/replication&version=2&generation=2&command=filelist&wt=javabin} status=0 QTime=2
[junit4:junit4] 2> 19997 T1520 C110 P39862 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 19998 T1520 C110 P39862 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3/index.20130305065737654 forceNew:false
[junit4:junit4] 2> 20007 T1520 C110 P39862 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3
[junit4:junit4] 2> 20008 T1520 C110 P39862 oash.SnapPuller.fetchLatestIndex Starting download to NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3/index.20130305065737654 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5d035d03; maxCacheMB=48.0 maxMergeSizeMB=4.0) fullCopy=false
[junit4:junit4] 2> 20011 T1480 C112 P33021 REQ /replication {checksum=true&qt=/replication&generation=2&command=filecontent&file=segments_2&wt=filestream} status=0 QTime=0
[junit4:junit4] 2> 20013 T1520 C110 P39862 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3/index
[junit4:junit4] 2> 20014 T1520 C110 P39862 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 20021 T1520 C110 P39862 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3
[junit4:junit4] 2> 20025 T1520 C110 P39862 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3
[junit4:junit4] 2> 20025 T1520 C110 P39862 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 20026 T1520 C110 P39862 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 20027 T1520 C110 P39862 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3
[junit4:junit4] 2> 20031 T1520 C110 P39862 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7980798; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7980798; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 20032 T1520 C110 P39862 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 20033 T1520 C110 P39862 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 20033 T1520 C110 P39862 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3
[junit4:junit4] 2> 20034 T1520 C110 P39862 oass.SolrIndexSearcher.<init> Opening Searcher@44a044a0 main
[junit4:junit4] 2> 20036 T1519 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@44a044a0 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 20037 T1519 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3/index
[junit4:junit4] 2> 20038 T1520 C110 P39862 oash.SnapPuller.fetchLatestIndex removing temporary index download directory files NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3/index.20130305065737654 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5d035d03; maxCacheMB=48.0 maxMergeSizeMB=4.0)
[junit4:junit4] 2> 20039 T1520 C110 P39862 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3/index.20130305065737654
[junit4:junit4] 2> 20040 T1520 C110 P39862 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty3/index
[junit4:junit4] 2> 20041 T1520 C110 P39862 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 20041 T1520 C110 P39862 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 20042 T1520 C110 P39862 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 20042 T1520 C110 P39862 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 20045 T1520 C110 P39862 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 20305 T1482 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 20310 T1482 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 20313 T1482 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 20336 T1482 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 20342 T1482 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 20347 T1482 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 20350 T1482 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 20350 T1482 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 20351 T1482 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 20354 T1482 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 20354 T1482 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 20355 T1482 oasc.SolrCore.<init> [onenodecollectioncore] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362455841565/onenodecollectioncore/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362455837660/onenodecollection/
[junit4:junit4] 2> 20356 T1482 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2630263
[junit4:junit4] 2> 20357 T1482 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4] 2> 20358 T1482 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362455837660/onenodecollection forceNew:false
[junit4:junit4] 2> 20359 T1482 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362455837660/onenodecollection
[junit4:junit4] 2> 20360 T1482 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362455837660/onenodecollection/index/
[junit4:junit4] 2> 20360 T1482 oasc.SolrCore.initIndex WARNING [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362455837660/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 20361 T1482 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362455837660/onenodecollection/index forceNew:false
[junit4:junit4] 2> 20383 T1482 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solrtest-BasicDistributedZk2Test-1362455837660/onenodecollection/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@499a499a; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 20384 T1482 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 20385 T1482 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362455837660/onenodecollection/index
[junit4:junit4] 2> 20388 T1482 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 20389 T1482 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 20390 T1482 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 20391 T1482 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 20392 T1482 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 20393 T1482 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 20394 T1482 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 20395 T1482 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 20396 T1482 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 20397 T1482 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 20400 T1482 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362455837660/onenodecollection
[junit4:junit4] 2> 20401 T1482 oass.SolrIndexSearcher.<init> Opening Searcher@54af54af main
[junit4:junit4] 2> 20403 T1482 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 20403 T1482 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 20420 T1482 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362455837660/onenodecollection
[junit4:junit4] 2> 20422 T1539 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@54af54af main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 20425 T1482 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> 20645 T1469 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 20646 T1469 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:40647/gd_i/b",
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:40647_gd_i%2Fb",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 20652 T1469 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:39862/gd_i/b",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:39862_gd_i%2Fb",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 20657 T1469 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:33021/gd_i/b",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:33021_gd_i%2Fb",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"onenodecollectioncore"}
[junit4:junit4] 2> 20658 T1469 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4] 2> 20658 T1469 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 20664 T1474 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20664 T1468 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20664 T1487 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20664 T1517 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20664 T1533 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20664 T1502 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 21427 T1482 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4] 2> 21428 T1482 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:33021/gd_i/b collection:onenodecollection shard:shard1
[junit4:junit4] 2> 21430 T1482 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4] 2> 21442 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10006 type:delete cxid:0xa6 zxid:0xc3 txntype:-1 reqpath:n/a Error Path:/solr/collections/onenodecollection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/onenodecollection/leaders
[junit4:junit4] 2> 21443 T1482 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 21444 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10006 type:create cxid:0xa7 zxid:0xc4 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 21447 T1482 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 21448 T1482 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 21448 T1482 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:33021/gd_i/b/onenodecollectioncore/
[junit4:junit4] 2> 21449 T1482 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 21450 T1482 oasc.SyncStrategy.syncToMe http://127.0.0.1:33021/gd_i/b/onenodecollectioncore/ has no replicas
[junit4:junit4] 2> 21450 T1482 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:33021/gd_i/b/onenodecollectioncore/
[junit4:junit4] 2> 21451 T1482 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4] 2> 21459 T1451 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d38b23be10006 type:create cxid:0xb1 zxid:0xc8 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 22182 T1469 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 22194 T1468 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 22194 T1517 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 22194 T1502 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 22194 T1474 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 22194 T1487 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 22194 T1533 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 22214 T1482 oasc.ZkController.register We are http://127.0.0.1:33021/gd_i/b/onenodecollectioncore/ and leader is http://127.0.0.1:33021/gd_i/b/onenodecollectioncore/
[junit4:junit4] 2> 22215 T1482 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:33021/gd_i/b
[junit4:junit4] 2> 22216 T1482 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 22216 T1482 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4] 2> 22220 T1482 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 22249 T1446 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4] 2> 22250 T1446 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> C111_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:40647/gd_i/b, state=recovering, node_name=127.0.0.1:40647_gd_i%2Fb, collection=collection1, shard=shard2, core=collection1}
[junit4:junit4] 2> 22769 T1536 C111 P40647 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:43455/gd_i/b/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 22769 T1536 C111 P40647 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:40647/gd_i/b START replicas=[http://127.0.0.1:43455/gd_i/b/collection1/] nUpdates=100
[junit4:junit4] 2> 22770 T1536 C111 P40647 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 22770 T1536 C111 P40647 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 22771 T1536 C111 P40647 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 22771 T1536 C111 P40647 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 22771 T1536 C111 P40647 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 22772 T1536 C111 P40647 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:43455/gd_i/b/collection1/. core=collection1
[junit4:junit4] 2> 22772 T1536 C111 P40647 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C113 name=collection1 org.apache.solr.core.SolrCore@68ed68ed url=http://127.0.0.1:43455/gd_i/b/collection1 node=127.0.0.1:43455_gd_i%2Fb C113_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:43455/gd_i/b, state=active, node_name=127.0.0.1:43455_gd_i%2Fb, collection=collection1, shard=shard2, core=collection1, leader=true}
[junit4:junit4] 2> 22774 T1498 C113 P43455 REQ /get {getVersions=100&qt=/get&distrib=false&version=2&wt=javabin} status=0 QTime=0
[junit4:junit4] 2> 22779 T1497 C113 P43455 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 22780 T1497 C113 P43455 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty2
[junit4:junit4] 2> 22784 T1497 C113 P43455 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@16311631; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 22785 T1497 C113 P43455 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 22790 T1497 C113 P43455 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@16311631; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@16311631; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 22791 T1497 C113 P43455 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 22793 T1497 C113 P43455 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty2
[junit4:junit4] 2> 22793 T1497 C113 P43455 oass.SolrIndexSearcher.<init> Opening Searcher@2c5d2c5d realtime
[junit4:junit4] 2> 22794 T1497 C113 P43455 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 22795 T1497 C113 P43455 /update {softCommit=false&commit_end_point=true&commit=true&version=2&waitSearcher=true&wt=javabin&openSearcher=false} {commit=} 0 16
[junit4:junit4] 2> 22796 T1536 C111 P40647 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 22797 T1536 C111 P40647 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 22798 T1498 C113 P43455 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 22799 T1498 C113 P43455 REQ /replication {qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 22800 T1536 C111 P40647 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 22800 T1536 C111 P40647 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 22800 T1536 C111 P40647 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 22803 T1496 C113 P43455 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty2
[junit4:junit4] 2> 22804 T1496 C113 P43455 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty2/index
[junit4:junit4] 2> 22805 T1496 C113 P43455 REQ /replication {qt=/replication&version=2&generation=2&command=filelist&wt=javabin} status=0 QTime=3
[junit4:junit4] 2> 22806 T1536 C111 P40647 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 22807 T1536 C111 P40647 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4/index.20130305065740463 forceNew:false
[junit4:junit4] 2> 22808 T1536 C111 P40647 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4
[junit4:junit4] 2> 22808 T1536 C111 P40647 oash.SnapPuller.fetchLatestIndex Starting download to NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4/index.20130305065740463 lockFactory=org.apache.lucene.store.NativeFSLockFactory@11741174; maxCacheMB=48.0 maxMergeSizeMB=4.0) fullCopy=false
[junit4:junit4] 2> 22811 T1497 C113 P43455 REQ /replication {checksum=true&qt=/replication&generation=2&command=filecontent&file=segments_2&wt=filestream} status=0 QTime=0
[junit4:junit4] 2> 22812 T1536 C111 P40647 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4/index
[junit4:junit4] 2> 22813 T1536 C111 P40647 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 22821 T1536 C111 P40647 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4
[junit4:junit4] 2> 22822 T1536 C111 P40647 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4
[junit4:junit4] 2> 22822 T1536 C111 P40647 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 22823 T1536 C111 P40647 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 22823 T1536 C111 P40647 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4
[junit4:junit4] 2> 22826 T1536 C111 P40647 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2b152b15; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2b152b15; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 22827 T1536 C111 P40647 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 22827 T1536 C111 P40647 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 22828 T1536 C111 P40647 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4
[junit4:junit4] 2> 22828 T1536 C111 P40647 oass.SolrIndexSearcher.<init> Opening Searcher@3d283d28 main
[junit4:junit4] 2> 22830 T1535 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3d283d28 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 22830 T1535 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4/index
[junit4:junit4] 2> 22831 T1536 C111 P40647 oash.SnapPuller.fetchLatestIndex removing temporary index download directory files NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4/index.20130305065740463 lockFactory=org.apache.lucene.store.NativeFSLockFactory@11741174; maxCacheMB=48.0 maxMergeSizeMB=4.0)
[junit4:junit4] 2> 22831 T1536 C111 P40647 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4/index.20130305065740463
[junit4:junit4] 2> 22832 T1536 C111 P40647 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362455837660/jetty4/index
[junit4:junit4] 2> 22833 T1536 C111 P40647 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 22833 T1536 C111 P40647 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 22833 T1536 C111 P40647 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 22834 T1536 C111 P40647 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 22837 T1536 C111 P40647 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 23253 T1446 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 23707 T1469 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 23709 T1469 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:33021/gd_i/b",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:33021_gd_i%2Fb",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"onenodecollectioncore"}
[junit4:junit4] 2> 23714 T1469 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:40647/gd_i/b",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:40647_gd_i%2Fb",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 23720 T1517 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 23720 T1502 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 23721 T1468 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 23720 T1533 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 23721 T1474 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 23721 T1487 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 24255 T1446 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 24257 T1446 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4] 2> 24258 T1446 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 24276 T1446 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55158 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@606d606d
[junit4:junit4] 2> 24277 T1446 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 24277 T1542 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:55158. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 24278 T1542 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:55158, initiating session
[junit4:junit4] 2> 24278 T1448 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33289
[junit4:junit4] 2> 24279 T1448 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33289
[junit4:junit4] 2> 24281 T1450 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d38b23be1000d with negotiated timeout 10000 for client /127.0.0.1:33289
[junit4:junit4] 2> 24281 T1542 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:55158, sessionid = 0x13d38b23be1000d, negotiated timeout = 10000
[junit4:junit4] 2> 24282 T1543 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@606d606d name:ZooKeeperConnection Watcher:127.0.0.1:55158 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 24282 T1446 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[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 (6)
[junit4:junit4] 1> /solr/configs (1)
[junit4:junit4] 1> /solr/configs/conf1 (9)
[junit4:junit4] 1> /solr/configs/conf1/old_synonyms.txt (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/protwords.txt (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/stopwords.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/currency.xml (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> /solr/configs/conf1/solrconfig.xml (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/overseer_elect (2)
[junit4:junit4] 1> /solr/overseer_elect/leader (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"id":"89289905777213443-127.0.0.1:37767_gd_i%2Fb-n_0000000000"}
[junit4:junit4] 1> /solr/overseer_elect/election (5)
[junit4:junit4] 1> /solr/overseer_elect/election/89289905777213446-127.0.0.1:33021_gd_i%2Fb-n_0000000001 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89289905777213448-127.0.0.1:43455_gd_i%2Fb-n_0000000002 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89289905777213443-127.0.0.1:37767_gd_i%2Fb-n_0000000000 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89289905777213450-127.0.0.1:39862_gd_i%2Fb-n_0000000003 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89289905777213452-127.0.0.1:40647_gd_i%2Fb-n_0000000004 (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/collections (3)
[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/89289905777213443-127.0.0.1:37767_gd_i%2Fb_collection1-n_0000000000 (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:37767/gd_i/b",
[junit4:junit4] 1> "node_name":"127.0.0.1:37767_gd_i%2Fb",
[junit4:junit4] 1> "core":"collection1"}
[junit4:junit4] 1> /solr/collections/control_collection/shards (0)
[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/shard1 (1)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election (2)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/89289905777213446-127.0.0.1:33021_gd_i%2Fb_collection1-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/89289905777213450-127.0.0.1:39862_gd_i%2Fb_collection1-n_0000000001 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2 (1)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2/election (2)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2/election/89289905777213448-127.0.0.1:43455_gd_i%2Fb_collection1-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2/election/89289905777213452-127.0.0.1:40647_gd_i%2Fb_collection1-n_0000000001 (0)
[junit4:junit4] 1> /solr/collections/collection1/leaders (2)
[junit4:junit4] 1> /solr/collections/collection1/leaders/shard1 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "base_url":"http://127.0.0.1:33021/gd_i/b",
[junit4:junit4] 1> "node_name":"127.0.0.1:33021_gd_i%2Fb",
[junit4:junit4] 1> "core":"collection1"}
[junit4:junit
[...truncated too long message...]
"node_name":"127.0.0.1:40647_gd_i%2Fb",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "shard":"shard2",
[junit4:junit4] 1> "core":"collection1"}}}},
[junit4:junit4] 1> "router":"compositeId"}}
[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=631377AFE3CEB59 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=tr_TR -Dtests.timezone=Etc/GMT-3 -Dtests.file.encoding=UTF-8
[junit4:junit4] ERROR 33.0s J1 | BasicDistributedZk2Test.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.common.SolrException: Server at http://127.0.0.1:43455/gd_i/b/onenodecollectioncore returned non ok status:404, message:Can not find: /gd_i/b/onenodecollectioncore/update
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([631377AFE3CEB59:87D7B96289638B65]:0)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:373)
[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:196)
[junit4:junit4] > at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:85)
[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:60)
[junit4:junit4] > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
[junit4:junit4] > at java.lang.reflect.Method.invoke(Method.java:611)
[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:738)
[junit4:junit4] 2> 32993 T1446 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 33005 T1445 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4:junit4] 2> 33344 T1449 oazs.SessionTrackerImpl.run SessionTrackerImpl exited loop!
[junit4:junit4] 2> NOTE: test params are: codec=Lucene41, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=tr_TR, timezone=Etc/GMT-3
[junit4:junit4] 2> NOTE: Linux 3.2.0-38-generic x86/IBM Corporation 1.6.0 (32-bit)/cpus=8,threads=2,free=25849232,total=63743488
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestZkChroot, SliceStateUpdateTest, SolrCmdDistributorTest, MultiTermTest, TestRealTimeGet, TestNumberUtils, RegexBoostProcessorTest, TestLMJelinekMercerSimilarityFactory, TestBinaryResponseWriter, FullSolrCloudDistribCmdsTest, OverseerCollectionProcessorTest, DOMUtilTest, SimpleFacetsTest, TestFaceting, DisMaxRequestHandlerTest, NumericFieldsTest, TestSolrQueryParser, MBeansHandlerTest, SpellCheckComponentTest, FileUtilsTest, TermsComponentTest, FastVectorHighlighterTest, SimplePostToolTest, DirectSolrSpellCheckerTest, CoreAdminHandlerTest, SolrCoreCheckLockOnStartupTest, BasicFunctionalityTest, TestBinaryField, HighlighterTest, AutoCommitTest, TestWordDelimiterFilterFactory, DistributedQueryElevationComponentTest, SuggesterTest, NotRequiredUniqueKeyTest, TestPartialUpdateDeduplication, TestAtomicUpdateErrorCases, ClusterStateUpdateTest, TestSolr4Spatial, IndexBasedSpellCheckerTest, TermVectorComponentDistributedTest, TestUtils, TestBM25SimilarityFactory, DocValuesTest, TestReversedWildcardFilterFactory, DebugComponentTest, ClusterStateTest, TestRandomDVFaceting, ChaosMonkeySafeLeaderTest, PingRequestHandlerTest, ReturnFieldsTest, SortByFunctionTest, EchoParamsTest, TestCodecSupport, TestReload, UpdateRequestProcessorFactoryTest, TestPostingsSolrHighlighter, SampleTest, TestCSVLoader, TestMergePolicyConfig, BasicDistributedZk2Test]
[junit4:junit4] Completed on J1 in 33.53s, 1 test, 1 error <<< FAILURES!
[...truncated 457 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:381: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:374: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:183: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:449: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1213: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:877: There were test failures: 260 suites, 1098 tests, 1 error, 10 ignored (4 assumptions)
Total time: 45 minutes 19 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 32bit/ibm-j9-jdk6
Email was triggered for: Failure
Sending email for trigger: Failure