lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Linux (32bit/ibm-j9-jdk6) - Build # 4531 - Failure!
Date Fri, 01 Mar 2013 12:04:50 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/4531/
Java: 32bit/ibm-j9-jdk6 

1 tests failed.
REGRESSION:  org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch

Error Message:
expected:<1> but was:<0>

Stack Trace:
java.lang.AssertionError: expected:<1> but was:<0>
	at __randomizedtesting.SeedInfo.seed([C2EE8FAB9556DC53:430801B3E209BC6F]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.failNotEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:128)
	at org.junit.Assert.assertEquals(Assert.java:472)
	at org.junit.Assert.assertEquals(Assert.java:456)
	at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:209)
	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:89)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java: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 8329 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 1 T285 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4]   2> 4 T285 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362138567320
[junit4:junit4]   2> 5 T285 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 6 T286 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 7 T286 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 8 T286 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4]   2> 8 T286 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4]   2> 9 T286 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 10 T286 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4]   2> 106 T285 oasc.ZkTestServer.run start zk server on port:47063
[junit4:junit4]   2> 107 T285 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47063 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@d570d57
[junit4:junit4]   2> 108 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 108 T291 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47063. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 109 T291 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47063, initiating session
[junit4:junit4]   2> 109 T287 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:60335
[junit4:junit4]   2> 110 T287 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:60335
[junit4:junit4]   2> 110 T289 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 125 T289 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d25c9129d0000 with negotiated timeout 10000 for client /127.0.0.1:60335
[junit4:junit4]   2> 125 T291 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47063, sessionid = 0x13d25c9129d0000, negotiated timeout = 10000
[junit4:junit4]   2> 126 T292 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d570d57 name:ZooKeeperConnection Watcher:127.0.0.1:47063 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 126 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 127 T285 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 135 T290 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d25c9129d0000
[junit4:junit4]   2> 135 T287 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:60335 which had sessionid 0x13d25c9129d0000
[junit4:junit4]   2> 135 T285 oaz.ZooKeeper.close Session: 0x13d25c9129d0000 closed
[junit4:junit4]   2> 136 T292 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 136 T285 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47063/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@331d331d
[junit4:junit4]   2> 138 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 138 T293 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47063. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 139 T293 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47063, initiating session
[junit4:junit4]   2> 139 T287 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:60336
[junit4:junit4]   2> 140 T287 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:60336
[junit4:junit4]   2> 141 T289 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d25c9129d0001 with negotiated timeout 10000 for client /127.0.0.1:60336
[junit4:junit4]   2> 141 T293 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47063, sessionid = 0x13d25c9129d0001, negotiated timeout = 10000
[junit4:junit4]   2> 142 T294 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@331d331d name:ZooKeeperConnection Watcher:127.0.0.1:47063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 142 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 143 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 174 T285 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 181 T285 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 186 T285 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 190 T285 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 191 T285 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 203 T285 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 205 T285 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 233 T285 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 234 T285 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 239 T285 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 240 T285 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 244 T285 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 245 T285 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 249 T285 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 250 T285 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 254 T285 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 255 T285 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 259 T285 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 260 T285 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 265 T285 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 266 T285 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 272 T290 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d25c9129d0001
[junit4:junit4]   2> 273 T287 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:60336 which had sessionid 0x13d25c9129d0001
[junit4:junit4]   2> 273 T294 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 274 T285 oaz.ZooKeeper.close Session: 0x13d25c9129d0001 closed
[junit4:junit4]   2> 438 T285 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 443 T285 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50292
[junit4:junit4]   2> 444 T285 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 445 T285 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 446 T285 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362138567590
[junit4:junit4]   2> 447 T285 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362138567590/solr.xml
[junit4:junit4]   2> 448 T285 oasc.CoreContainer.<init> New CoreContainer 1070874580
[junit4:junit4]   2> 449 T285 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362138567590/'
[junit4:junit4]   2> 450 T285 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362138567590/'
[junit4:junit4]   2> 473 T285 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 474 T285 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 475 T285 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 476 T285 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 476 T285 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 477 T285 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 478 T285 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 479 T285 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 480 T285 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 481 T285 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 495 T285 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 512 T285 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:47063/solr
[junit4:junit4]   2> 513 T285 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 514 T285 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47063 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@6b7b6b7b
[junit4:junit4]   2> 515 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 516 T304 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47063. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 517 T304 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47063, initiating session
[junit4:junit4]   2> 517 T287 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:60337
[junit4:junit4]   2> 518 T287 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:60337
[junit4:junit4]   2> 521 T289 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d25c9129d0002 with negotiated timeout 20000 for client /127.0.0.1:60337
[junit4:junit4]   2> 522 T304 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47063, sessionid = 0x13d25c9129d0002, negotiated timeout = 20000
[junit4:junit4]   2> 523 T305 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b7b6b7b name:ZooKeeperConnection Watcher:127.0.0.1:47063 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 523 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 528 T290 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d25c9129d0002
[junit4:junit4]   2> 529 T287 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:60337 which had sessionid 0x13d25c9129d0002
[junit4:junit4]   2> 530 T305 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 530 T285 oaz.ZooKeeper.close Session: 0x13d25c9129d0002 closed
[junit4:junit4]   2> 532 T285 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 538 T285 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47063/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@24a124a1
[junit4:junit4]   2> 540 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 540 T306 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47063. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 541 T306 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47063, initiating session
[junit4:junit4]   2> 541 T287 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:60338
[junit4:junit4]   2> 542 T287 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:60338
[junit4:junit4]   2> 544 T289 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d25c9129d0003 with negotiated timeout 20000 for client /127.0.0.1:60338
[junit4:junit4]   2> 544 T306 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47063, sessionid = 0x13d25c9129d0003, negotiated timeout = 20000
[junit4:junit4]   2> 545 T307 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@24a124a1 name:ZooKeeperConnection Watcher:127.0.0.1:47063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 546 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 549 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 555 T285 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 564 T285 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50292_
[junit4:junit4]   2> 566 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:50292_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:50292_
[junit4:junit4]   2> 566 T285 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50292_
[junit4:junit4]   2> 572 T285 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 587 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0003 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> 593 T285 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 598 T285 oasc.Overseer.start Overseer (id=89269113148211203-127.0.0.1:50292_-n_0000000000) starting
[junit4:junit4]   2> 599 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 602 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 603 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 604 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 605 T309 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 607 T285 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 612 T285 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 616 T308 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 619 T310 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362138567590/collection1
[junit4:junit4]   2> 620 T310 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 621 T310 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 621 T310 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 623 T310 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362138567590/collection1/'
[junit4:junit4]   2> 624 T310 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362138567590/collection1/lib/README' to classloader
[junit4:junit4]   2> 625 T310 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362138567590/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 679 T310 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 714 T310 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 716 T310 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 721 T310 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1114 T310 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1119 T310 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1123 T310 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1143 T310 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1148 T310 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1153 T310 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1155 T310 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1157 T310 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362138567590/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/control/data/
[junit4:junit4]   2> 1157 T310 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@591e591e
[junit4:junit4]   2> 1158 T310 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 1159 T310 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/control/data forceNew:false
[junit4:junit4]   2> 1160 T310 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/control/data
[junit4:junit4]   2> 1160 T310 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/control/data/index/
[junit4:junit4]   2> 1161 T310 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1161 T310 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/control/data/index forceNew:false
[junit4:junit4]   2> 1164 T310 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@77e077e lockFactory=org.apache.lucene.store.NativeFSLockFactory@4a664a66),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1164 T310 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 1165 T310 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/control/data/index
[junit4:junit4]   2> 1167 T310 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1168 T310 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1169 T310 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1169 T310 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1170 T310 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1171 T310 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1171 T310 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1172 T310 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1172 T310 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1174 T310 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1176 T310 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/control/data
[junit4:junit4]   2> 1177 T310 oass.SolrIndexSearcher.<init> Opening Searcher@58b058b main
[junit4:junit4]   2> 1177 T310 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/control/data/tlog
[junit4:junit4]   2> 1178 T310 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1179 T310 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1186 T311 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@58b058b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1199 T310 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 1200 T310 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1201 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0003 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> 2121 T308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2123 T308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50292",
[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:50292_",
[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> 2123 T308 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 2124 T308 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 2125 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0003 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> 2148 T307 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> 2221 T310 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 2222 T310 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50292 collection:control_collection shard:shard1
[junit4:junit4]   2> 2223 T310 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 2243 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0003 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> 2254 T310 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 2254 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0003 type:create cxid:0x73 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2266 T310 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2267 T310 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2267 T310 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50292/collection1/
[junit4:junit4]   2> 2268 T310 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 2268 T310 oasc.SyncStrategy.syncToMe http://127.0.0.1:50292/collection1/ has no replicas
[junit4:junit4]   2> 2269 T310 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50292/collection1/
[junit4:junit4]   2> 2269 T310 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 2278 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0003 type:create cxid:0x7d zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3657 T308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3716 T307 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> 3750 T310 oasc.ZkController.register We are http://127.0.0.1:50292/collection1/ and leader is http://127.0.0.1:50292/collection1/
[junit4:junit4]   2> 3751 T310 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50292
[junit4:junit4]   2> 3751 T310 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 3752 T310 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 3752 T310 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 3764 T310 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3765 T285 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 3766 T285 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 3768 T285 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 3777 T285 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 3779 T285 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47063/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1200120
[junit4:junit4]   2> 3781 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3781 T312 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47063. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 3782 T312 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47063, initiating session
[junit4:junit4]   2> 3782 T287 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:60340
[junit4:junit4]   2> 3783 T287 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:60340
[junit4:junit4]   2> 3785 T289 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d25c9129d0004 with negotiated timeout 10000 for client /127.0.0.1:60340
[junit4:junit4]   2> 3785 T312 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47063, sessionid = 0x13d25c9129d0004, negotiated timeout = 10000
[junit4:junit4]   2> 3786 T313 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1200120 name:ZooKeeperConnection Watcher:127.0.0.1:47063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3787 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3788 T285 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3791 T285 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 3899 T285 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 3901 T285 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:39581
[junit4:junit4]   2> 3902 T285 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 3902 T285 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3903 T285 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362138571107
[junit4:junit4]   2> 3910 T285 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362138571107/solr.xml
[junit4:junit4]   2> 3911 T285 oasc.CoreContainer.<init> New CoreContainer 83035379
[junit4:junit4]   2> 3912 T285 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362138571107/'
[junit4:junit4]   2> 3913 T285 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362138571107/'
[junit4:junit4]   2> 3940 T285 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 3941 T285 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 3942 T285 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 3942 T285 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 3943 T285 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 3943 T285 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 3944 T285 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 3945 T285 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 3946 T285 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 3947 T285 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 3957 T285 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 3969 T285 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:47063/solr
[junit4:junit4]   2> 3970 T285 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 3971 T285 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47063 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@13ff13ff
[junit4:junit4]   2> 3972 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3973 T323 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47063. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 3974 T323 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47063, initiating session
[junit4:junit4]   2> 3974 T287 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:60341
[junit4:junit4]   2> 3975 T287 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:60341
[junit4:junit4]   2> 3984 T289 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d25c9129d0005 with negotiated timeout 20000 for client /127.0.0.1:60341
[junit4:junit4]   2> 3984 T323 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47063, sessionid = 0x13d25c9129d0005, negotiated timeout = 20000
[junit4:junit4]   2> 3985 T324 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13ff13ff name:ZooKeeperConnection Watcher:127.0.0.1:47063 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3985 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3987 T290 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d25c9129d0005
[junit4:junit4]   2> 3988 T324 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 3988 T287 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:60341 which had sessionid 0x13d25c9129d0005
[junit4:junit4]   2> 3988 T285 oaz.ZooKeeper.close Session: 0x13d25c9129d0005 closed
[junit4:junit4]   2> 3990 T285 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 3999 T285 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47063/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@39e939e9
[junit4:junit4]   2> 4001 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4001 T325 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47063. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 4002 T325 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47063, initiating session
[junit4:junit4]   2> 4002 T287 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:60342
[junit4:junit4]   2> 4003 T287 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:60342
[junit4:junit4]   2> 4014 T289 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d25c9129d0006 with negotiated timeout 20000 for client /127.0.0.1:60342
[junit4:junit4]   2> 4014 T325 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47063, sessionid = 0x13d25c9129d0006, negotiated timeout = 20000
[junit4:junit4]   2> 4016 T326 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@39e939e9 name:ZooKeeperConnection Watcher:127.0.0.1:47063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4016 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4018 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0006 type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4024 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0006 type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4027 T285 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 5033 T285 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39581_
[junit4:junit4]   2> 5034 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0006 type:delete cxid:0x9 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:39581_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:39581_
[junit4:junit4]   2> 5036 T285 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39581_
[junit4:junit4]   2> 5039 T307 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> 5040 T313 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5040 T326 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5043 T307 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5049 T327 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362138571107/collection1
[junit4:junit4]   2> 5049 T327 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 5051 T327 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 5051 T327 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 5054 T327 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362138571107/collection1/'
[junit4:junit4]   2> 5055 T327 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362138571107/collection1/lib/README' to classloader
[junit4:junit4]   2> 5055 T327 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362138571107/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 5088 T327 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 5136 T327 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 5137 T327 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 5144 T327 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 5269 T308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5271 T308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50292",
[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:50292_",
[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> 5279 T307 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> 5279 T326 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> 5279 T313 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> 5588 T327 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 5593 T327 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 5596 T327 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 5616 T327 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5621 T327 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5626 T327 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5630 T327 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5633 T327 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362138571107/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1/
[junit4:junit4]   2> 5633 T327 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@591e591e
[junit4:junit4]   2> 5634 T327 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 5635 T327 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1 forceNew:false
[junit4:junit4]   2> 5636 T327 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1
[junit4:junit4]   2> 5636 T327 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1/index/
[junit4:junit4]   2> 5637 T327 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 5637 T327 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1/index forceNew:false
[junit4:junit4]   2> 5639 T327 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3a283a28 lockFactory=org.apache.lucene.store.NativeFSLockFactory@23be23be),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 5640 T327 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 5641 T327 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1/index
[junit4:junit4]   2> 5643 T327 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 5644 T327 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 5645 T327 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 5646 T327 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 5646 T327 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 5647 T327 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 5648 T327 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 5648 T327 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 5649 T327 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 5650 T327 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 5653 T327 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1
[junit4:junit4]   2> 5653 T327 oass.SolrIndexSearcher.<init> Opening Searcher@41784178 main
[junit4:junit4]   2> 5654 T327 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1/tlog
[junit4:junit4]   2> 5655 T327 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 5655 T327 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 5663 T328 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@41784178 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 5667 T327 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 5667 T327 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 6793 T308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6794 T308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:39581",
[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:39581_",
[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> 6795 T308 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4]   2> 6795 T308 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 6854 T313 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> 6854 T326 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> 6854 T307 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> 7669 T327 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 7670 T327 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:39581 collection:collection1 shard:shard1
[junit4:junit4]   2> 7671 T327 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 7972 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0006 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> 7973 T327 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 7974 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0006 type:create cxid:0x47 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7977 T327 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 7977 T327 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 7978 T327 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:39581/collection1/
[junit4:junit4]   2> 7979 T327 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 7979 T327 oasc.SyncStrategy.syncToMe http://127.0.0.1:39581/collection1/ has no replicas
[junit4:junit4]   2> 7980 T327 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:39581/collection1/
[junit4:junit4]   2> 7981 T327 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 7988 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0006 type:create cxid:0x51 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8378 T308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8390 T307 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> 8390 T326 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> 8390 T313 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> 8442 T327 oasc.ZkController.register We are http://127.0.0.1:39581/collection1/ and leader is http://127.0.0.1:39581/collection1/
[junit4:junit4]   2> 8443 T327 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39581
[junit4:junit4]   2> 8444 T327 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 8444 T327 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 8444 T327 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 8447 T327 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8449 T285 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 8450 T285 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 8451 T285 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 8583 T285 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 8585 T285 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:32998
[junit4:junit4]   2> 8586 T285 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 8587 T285 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8588 T285 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362138575772
[junit4:junit4]   2> 8588 T285 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362138575772/solr.xml
[junit4:junit4]   2> 8589 T285 oasc.CoreContainer.<init> New CoreContainer 1103118784
[junit4:junit4]   2> 8590 T285 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362138575772/'
[junit4:junit4]   2> 8591 T285 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362138575772/'
[junit4:junit4]   2> 8608 T285 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 8608 T285 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 8609 T285 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 8610 T285 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 8610 T285 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 8611 T285 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 8612 T285 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 8612 T285 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 8613 T285 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 8614 T285 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 8624 T285 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 8636 T285 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:47063/solr
[junit4:junit4]   2> 8637 T285 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 8637 T285 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47063 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@7ebf7ebf
[junit4:junit4]   2> 8639 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8639 T338 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47063. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 8640 T338 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47063, initiating session
[junit4:junit4]   2> 8640 T287 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:60348
[junit4:junit4]   2> 8641 T287 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:60348
[junit4:junit4]   2> 8642 T289 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d25c9129d0007 with negotiated timeout 20000 for client /127.0.0.1:60348
[junit4:junit4]   2> 8642 T338 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47063, sessionid = 0x13d25c9129d0007, negotiated timeout = 20000
[junit4:junit4]   2> 8643 T339 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ebf7ebf name:ZooKeeperConnection Watcher:127.0.0.1:47063 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8644 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8646 T290 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d25c9129d0007
[junit4:junit4]   2> 8647 T339 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 8647 T287 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:60348 which had sessionid 0x13d25c9129d0007
[junit4:junit4]   2> 8647 T285 oaz.ZooKeeper.close Session: 0x13d25c9129d0007 closed
[junit4:junit4]   2> 8648 T285 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 8655 T285 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47063/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@2b232b23
[junit4:junit4]   2> 8656 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8663 T340 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47063. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 8664 T340 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47063, initiating session
[junit4:junit4]   2> 8664 T287 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:60349
[junit4:junit4]   2> 8665 T287 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:60349
[junit4:junit4]   2> 8666 T289 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d25c9129d0008 with negotiated timeout 20000 for client /127.0.0.1:60349
[junit4:junit4]   2> 8666 T340 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47063, sessionid = 0x13d25c9129d0008, negotiated timeout = 20000
[junit4:junit4]   2> 8667 T341 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2b232b23 name:ZooKeeperConnection Watcher:127.0.0.1:47063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8667 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8669 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0008 type:create cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8670 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0008 type:create cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8673 T285 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9677 T285 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32998_
[junit4:junit4]   2> 9678 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0008 type:delete cxid:0x9 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:32998_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:32998_
[junit4:junit4]   2> 9679 T285 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:32998_
[junit4:junit4]   2> 9684 T313 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> 9684 T307 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> 9685 T326 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9686 T326 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> 9686 T341 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9688 T313 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9689 T307 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9695 T342 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362138575772/collection1
[junit4:junit4]   2> 9695 T342 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 9696 T342 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 9697 T342 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 9699 T342 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362138575772/collection1/'
[junit4:junit4]   2> 9700 T342 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362138575772/collection1/lib/README' to classloader
[junit4:junit4]   2> 9700 T342 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362138575772/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 9730 T342 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 9762 T342 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 9764 T342 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 9770 T342 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 9910 T308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9911 T308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:39581",
[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:39581_",
[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> 9920 T313 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> 9920 T307 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> 9920 T341 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> 9920 T326 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> 10173 T342 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 10179 T342 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 10182 T342 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 10202 T342 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10207 T342 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10212 T342 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10214 T342 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10216 T342 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362138575772/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty2/
[junit4:junit4]   2> 10217 T342 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@591e591e
[junit4:junit4]   2> 10218 T342 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 10219 T342 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty2 forceNew:false
[junit4:junit4]   2> 10219 T342 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty2
[junit4:junit4]   2> 10220 T342 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty2/index/
[junit4:junit4]   2> 10220 T342 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 10221 T342 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty2/index forceNew:false
[junit4:junit4]   2> 10223 T342 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6de66de6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7d9e7d9e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10224 T342 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 10225 T342 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty2/index
[junit4:junit4]   2> 10228 T342 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 10228 T342 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 10229 T342 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 10230 T342 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 10231 T342 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 10232 T342 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 10232 T342 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 10233 T342 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 10234 T342 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 10235 T342 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 10237 T342 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty2
[junit4:junit4]   2> 10238 T342 oass.SolrIndexSearcher.<init> Opening Searcher@19471947 main
[junit4:junit4]   2> 10239 T342 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty2/tlog
[junit4:junit4]   2> 10239 T342 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 10240 T342 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 10256 T343 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@19471947 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 10260 T342 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 10260 T342 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 11430 T308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11432 T308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:32998",
[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:32998_",
[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> 11433 T308 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 11433 T308 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4]   2> 11441 T313 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> 11441 T307 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> 11441 T341 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> 11441 T326 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> 12262 T342 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 12263 T342 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:32998 collection:collection1 shard:shard2
[junit4:junit4]   2> 12264 T342 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 12273 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0008 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> 12274 T342 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 12275 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0008 type:create cxid:0x46 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12277 T342 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 12278 T342 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 12278 T342 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:32998/collection1/
[junit4:junit4]   2> 12279 T342 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 12279 T342 oasc.SyncStrategy.syncToMe http://127.0.0.1:32998/collection1/ has no replicas
[junit4:junit4]   2> 12279 T342 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:32998/collection1/
[junit4:junit4]   2> 12280 T342 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 12286 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0008 type:create cxid:0x4f zxid:0x82 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12950 T308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12960 T313 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> 12960 T341 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> 12960 T326 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> 12960 T307 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> 12990 T342 oasc.ZkController.register We are http://127.0.0.1:32998/collection1/ and leader is http://127.0.0.1:32998/collection1/
[junit4:junit4]   2> 12991 T342 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:32998
[junit4:junit4]   2> 12992 T342 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 12993 T342 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 12993 T342 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 12996 T342 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12998 T285 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 12999 T285 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 13000 T285 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 13128 T285 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 13130 T285 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:38370
[junit4:junit4]   2> 13131 T285 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 13131 T285 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 13132 T285 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362138580322
[junit4:junit4]   2> 13133 T285 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362138580322/solr.xml
[junit4:junit4]   2> 13133 T285 oasc.CoreContainer.<init> New CoreContainer 96077242
[junit4:junit4]   2> 13134 T285 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362138580322/'
[junit4:junit4]   2> 13135 T285 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362138580322/'
[junit4:junit4]   2> 13159 T285 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 13160 T285 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 13160 T285 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 13161 T285 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 13162 T285 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 13162 T285 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 13163 T285 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 13164 T285 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 13164 T285 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 13165 T285 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 13175 T285 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 13187 T285 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:47063/solr
[junit4:junit4]   2> 13188 T285 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 13189 T285 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47063 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@18151815
[junit4:junit4]   2> 13190 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 13191 T353 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47063. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 13192 T353 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47063, initiating session
[junit4:junit4]   2> 13192 T287 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:60350
[junit4:junit4]   2> 13193 T287 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:60350
[junit4:junit4]   2> 13194 T289 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d25c9129d0009 with negotiated timeout 20000 for client /127.0.0.1:60350
[junit4:junit4]   2> 13194 T353 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47063, sessionid = 0x13d25c9129d0009, negotiated timeout = 20000
[junit4:junit4]   2> 13195 T354 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18151815 name:ZooKeeperConnection Watcher:127.0.0.1:47063 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 13196 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 13198 T290 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d25c9129d0009
[junit4:junit4]   2> 13199 T287 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:60350 which had sessionid 0x13d25c9129d0009
[junit4:junit4]   2> 13199 T285 oaz.ZooKeeper.close Session: 0x13d25c9129d0009 closed
[junit4:junit4]   2> 13199 T354 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 13200 T285 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 13207 T285 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47063/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@24b624b6
[junit4:junit4]   2> 13209 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 13210 T355 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47063. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 13210 T355 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47063, initiating session
[junit4:junit4]   2> 13211 T287 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:60351
[junit4:junit4]   2> 13212 T287 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:60351
[junit4:junit4]   2> 13213 T289 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d25c9129d000a with negotiated timeout 20000 for client /127.0.0.1:60351
[junit4:junit4]   2> 13213 T355 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47063, sessionid = 0x13d25c9129d000a, negotiated timeout = 20000
[junit4:junit4]   2> 13214 T356 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@24b624b6 name:ZooKeeperConnection Watcher:127.0.0.1:47063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 13214 T285 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 13216 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d000a type:create cxid:0x1 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 13217 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d000a type:create cxid:0x2 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 13220 T285 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 14225 T285 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38370_
[junit4:junit4]   2> 14226 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d000a type:delete cxid:0x9 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:38370_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:38370_
[junit4:junit4]   2> 14227 T285 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38370_
[junit4:junit4]   2> 14231 T313 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> 14231 T341 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> 14231 T307 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> 14232 T356 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14232 T326 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14233 T326 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> 14234 T313 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14238 T341 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14238 T307 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14245 T357 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362138580322/collection1
[junit4:junit4]   2> 14246 T357 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 14247 T357 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 14247 T357 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 14250 T357 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362138580322/collection1/'
[junit4:junit4]   2> 14251 T357 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362138580322/collection1/lib/README' to classloader
[junit4:junit4]   2> 14251 T357 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362138580322/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 14293 T357 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 14330 T357 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 14332 T357 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 14338 T357 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 14472 T308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14474 T308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:32998",
[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:32998_",
[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> 14481 T326 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> 14481 T356 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> 14481 T307 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> 14482 T341 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> 14488 T313 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> 14827 T357 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 14832 T357 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 14835 T357 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 14861 T357 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14866 T357 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14872 T357 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14875 T357 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14877 T357 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362138580322/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3/
[junit4:junit4]   2> 14878 T357 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@591e591e
[junit4:junit4]   2> 14879 T357 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 14881 T357 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3 forceNew:false
[junit4:junit4]   2> 14881 T357 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3
[junit4:junit4]   2> 14882 T357 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3/index/
[junit4:junit4]   2> 14883 T357 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 14884 T357 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3/index forceNew:false
[junit4:junit4]   2> 14887 T357 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1f801f8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@47a347a3),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 14888 T357 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 14889 T357 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3/index
[junit4:junit4]   2> 14893 T357 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 14894 T357 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 14895 T357 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 14896 T357 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 14897 T357 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 14898 T357 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 14899 T357 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 14913 T357 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 14914 T357 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 14917 T357 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 14920 T357 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3
[junit4:junit4]   2> 14924 T357 oass.SolrIndexSearcher.<init> Opening Searcher@64976497 main
[junit4:junit4]   2> 14925 T357 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3/tlog
[junit4:junit4]   2> 14926 T357 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 14927 T357 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 17941 T358 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@64976497 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 17946 T357 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 17947 T357 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 18996 T308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18998 T308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:38370",
[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:38370_",
[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> 18998 T308 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 18999 T308 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 19093 T356 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> 19093 T307 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> 19093 T326 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> 19094 T341 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> 19093 T313 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> 19950 T357 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 19951 T357 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:38370 collection:collection1 shard:shard1
[junit4:junit4]   2> 19956 T357 oasc.ZkController.register We are http://127.0.0.1:38370/collection1/ and leader is http://127.0.0.1:39581/collection1/
[junit4:junit4]   2> 19956 T357 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38370
[junit4:junit4]   2> 19956 T357 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 19957 T357 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C16 name=collection1 org.apache.solr.core.SolrCore@4b974b97 url=http://127.0.0.1:38370/collection1 node=127.0.0.1:38370_ C16_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:38370, state=down, node_name=127.0.0.1:38370_, collection=collection1, core=collection1}
[junit4:junit4]   2> 19957 T359 C16 P38370 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 19958 T359 C16 P38370 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 19958 T357 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19959 T359 C16 P38370 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 19960 T359 C16 P38370 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 19961 T285 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 19962 T359 C16 P38370 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 19962 T285 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 19965 T285 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 19976 T285 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19979 T285 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 19986 T321 oasc.CoreContainer.create Creating SolrCore 'onenodecollectioncore' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362138571107/onenodecollectioncore
[junit4:junit4]   2> 19987 T321 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4]   2> 19988 T321 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4]   2> 19989 T321 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4]   2> 19992 T321 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4]   2> 19993 T321 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4]   2> 19999 T321 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4]   2> 20003 T321 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362138571107/onenodecollectioncore/'
[junit4:junit4]   2> 20048 T321 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 20086 T321 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 20088 T321 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 20094 T321 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 20512 T321 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 20519 T321 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 20522 T321 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 20551 T321 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 20558 T321 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 20564 T321 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 20567 T321 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 20569 T321 oasc.SolrCore.<init> [onenodecollectioncore] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362138571107/onenodecollectioncore/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362138567320/onenodecollection/
[junit4:junit4]   2> 20570 T321 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@591e591e
[junit4:junit4]   2> 20571 T321 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 20572 T321 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362138567320/onenodecollection forceNew:false
[junit4:junit4]   2> 20573 T321 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362138567320/onenodecollection
[junit4:junit4]   2> 20574 T321 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362138567320/onenodecollection/index/
[junit4:junit4]   2> 20575 T321 oasc.SolrCore.initIndex WARNING [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362138567320/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 20575 T321 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362138567320/onenodecollection/index forceNew:false
[junit4:junit4]   2> 20578 T321 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@77f677f6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@461e461e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 20579 T321 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 20580 T321 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362138567320/onenodecollection/index
[junit4:junit4]   2> 20583 T321 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 20584 T321 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 20586 T321 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 20587 T321 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 20589 T321 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 20590 T321 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 20591 T321 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 20592 T321 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 20594 T321 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 20596 T321 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 20599 T321 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362138567320/onenodecollection
[junit4:junit4]   2> 20600 T321 oass.SolrIndexSearcher.<init> Opening Searcher@2b352b35 main
[junit4:junit4]   2> 20603 T321 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362138567320/onenodecollection/tlog
[junit4:junit4]   2> 20605 T321 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 20606 T321 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 20608 T308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20610 T308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:38370",
[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:38370_",
[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> 20614 T321 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362138567320/onenodecollection
[junit4:junit4]   2> 20617 T360 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@2b352b35 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 20617 T313 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> 20617 T341 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> 20617 T356 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> 20617 T307 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> 20618 T326 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> 20625 T321 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4]   2> 22170 T308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22172 T308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:39581",
[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:39581_",
[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> 22172 T308 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4]   2> 22173 T308 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 22248 T313 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> 22248 T307 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> 22248 T356 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> 22249 T326 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> 22249 T341 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> 22627 T321 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4]   2> 22628 T321 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:39581 collection:onenodecollection shard:shard1
[junit4:junit4]   2> 22630 T321 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4]   2> 22640 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0006 type:delete cxid:0xa1 zxid:0xad txntype:-1 reqpath:n/a Error Path:/solr/collections/onenodecollection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/onenodecollection/leaders
[junit4:junit4]   2> 22641 T321 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 22643 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0006 type:create cxid:0xa2 zxid:0xae txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 22645 T321 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 22646 T321 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 22648 T321 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:39581/onenodecollectioncore/
[junit4:junit4]   2> 22649 T321 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 22650 T321 oasc.SyncStrategy.syncToMe http://127.0.0.1:39581/onenodecollectioncore/ has no replicas
[junit4:junit4]   2> 22651 T321 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:39581/onenodecollectioncore/
[junit4:junit4]   2> 22652 T321 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4]   2> 22659 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0006 type:create cxid:0xac zxid:0xb2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2>  C16_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:38370, state=recovering, node_name=127.0.0.1:38370_, collection=collection1, shard=shard1, core=collection1}
[junit4:junit4]   2> 22978 T359 C16 P38370 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:39581/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 22978 T359 C16 P38370 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:38370 START replicas=[http://127.0.0.1:39581/collection1/] nUpdates=100
[junit4:junit4]   2> 22979 T359 C16 P38370 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 22980 T359 C16 P38370 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 22980 T359 C16 P38370 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 22981 T359 C16 P38370 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 22981 T359 C16 P38370 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 22982 T359 C16 P38370 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:39581/collection1/. core=collection1
[junit4:junit4]   2> 22982 T359 C16 P38370 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C17 name=collection1 org.apache.solr.core.SolrCore@2a3f2a3f url=http://127.0.0.1:39581/collection1 node=127.0.0.1:39581_ C17_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:39581, state=active, node_name=127.0.0.1:39581_, collection=collection1, shard=shard1, core=collection1, leader=true}
[junit4:junit4]   2> 22985 T320 C17 P39581 REQ /get {getVersions=100&qt=/get&distrib=false&version=2&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 22993 T322 C17 P39581 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 22994 T322 C17 P39581 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1
[junit4:junit4]   2> 22996 T322 C17 P39581 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3a283a28 lockFactory=org.apache.lucene.store.NativeFSLockFactory@23be23be),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 22997 T322 C17 P39581 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 22998 T322 C17 P39581 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3a283a28 lockFactory=org.apache.lucene.store.NativeFSLockFactory@23be23be),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3a283a28 lockFactory=org.apache.lucene.store.NativeFSLockFactory@23be23be),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 22999 T322 C17 P39581 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 23000 T322 C17 P39581 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1
[junit4:junit4]   2> 23000 T322 C17 P39581 oass.SolrIndexSearcher.<init> Opening Searcher@72f072f0 realtime
[junit4:junit4]   2> 23001 T322 C17 P39581 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 23002 T322 C17 P39581 /update {softCommit=false&commit_end_point=true&commit=true&version=2&waitSearcher=true&wt=javabin&openSearcher=false} {commit=} 0 9
[junit4:junit4]   2> 23003 T359 C16 P38370 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 23004 T359 C16 P38370 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 23007 T319 C17 P39581 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 23008 T319 C17 P39581 REQ /replication {qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=2 
[junit4:junit4]   2> 23009 T359 C16 P38370 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 23010 T359 C16 P38370 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 23010 T359 C16 P38370 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 23013 T322 C17 P39581 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1
[junit4:junit4]   2> 23014 T322 C17 P39581 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1/index
[junit4:junit4]   2> 23015 T322 C17 P39581 REQ /replication {qt=/replication&version=2&generation=2&command=filelist&wt=javabin} status=0 QTime=3 
[junit4:junit4]   2> 23016 T359 C16 P38370 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 23017 T359 C16 P38370 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3/index.20130301054950331 forceNew:false
[junit4:junit4]   2> 23017 T359 C16 P38370 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3
[junit4:junit4]   2> 23018 T359 C16 P38370 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@71e071e lockFactory=org.apache.lucene.store.NativeFSLockFactory@48d948d9) fullCopy=true
[junit4:junit4]   2> 23032 T320 C17 P39581 REQ /replication {checksum=true&qt=/replication&generation=2&command=filecontent&file=segments_2&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 23041 T359 C16 P38370 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3/index
[junit4:junit4]   2> 23042 T359 C16 P38370 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 23042 T359 C16 P38370 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130301054950331
[junit4:junit4]   2> 23043 T359 C16 P38370 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3
[junit4:junit4]   2> 23044 T359 C16 P38370 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3
[junit4:junit4]   2> 23044 T359 C16 P38370 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3/index/ new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3/index.20130301054950331
[junit4:junit4]   2> 23046 T359 C16 P38370 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@71e071e lockFactory=org.apache.lucene.store.NativeFSLockFactory@48d948d9),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 23047 T359 C16 P38370 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 23047 T359 C16 P38370 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3
[junit4:junit4]   2> 23048 T359 C16 P38370 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3
[junit4:junit4]   2> 23049 T359 C16 P38370 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 23049 T359 C16 P38370 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 23049 T359 C16 P38370 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 23050 T359 C16 P38370 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3/index.20130301054950331
[junit4:junit4]   2> 23051 T359 C16 P38370 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3
[junit4:junit4]   2> 23052 T359 C16 P38370 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@71e071e lockFactory=org.apache.lucene.store.NativeFSLockFactory@48d948d9),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 23052 T359 C16 P38370 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 23053 T359 C16 P38370 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 23053 T359 C16 P38370 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3
[junit4:junit4]   2> 23054 T359 C16 P38370 oass.SolrIndexSearcher.<init> Opening Searcher@10e410e4 main
[junit4:junit4]   2> 23056 T358 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@10e410e4 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 23056 T358 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3/index
[junit4:junit4]   2> 23057 T359 C16 P38370 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3/index.20130301054950331
[junit4:junit4]   2> 23057 T359 C16 P38370 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3/index
[junit4:junit4]   2> 23058 T359 C16 P38370 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 23058 T359 C16 P38370 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 23058 T359 C16 P38370 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 23059 T359 C16 P38370 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 23060 T359 C16 P38370 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 23759 T308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 23773 T308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:38370",
[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:38370_",
[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> 23779 T356 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> 23779 T326 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> 23779 T307 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> 23780 T341 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> 23780 T313 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> 23813 T321 oasc.ZkController.register We are http://127.0.0.1:39581/onenodecollectioncore/ and leader is http://127.0.0.1:39581/onenodecollectioncore/
[junit4:junit4]   2> 23814 T321 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:39581
[junit4:junit4]   2> 23815 T321 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 23816 T321 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4]   2> 23825 T321 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 23827 T285 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4]   2> 23829 T285 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 24831 T285 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 25328 T308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 25343 T308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:39581",
[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:39581_",
[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> 25348 T356 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> 25350 T307 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> 25350 T326 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> 25350 T313 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> 25351 T341 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> 25833 T285 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 25835 T285 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4]   2> 25836 T285 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2>  C16_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:38370, state=active, node_name=127.0.0.1:38370_, collection=collection1, shard=shard1, core=collection1}
[junit4:junit4]   2> 25904 T351 C16 P38370 /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39581/collection1/&version=2&wt=javabin} {add=[1 (1428305837514817536)]} 0 1
[junit4:junit4]   2> 25905 T320 C17 P39581 /update {version=2&wt=javabin} {add=[1 (1428305837514817536)]} 0 9
[junit4:junit4]   2> 25915 T321 C17 P39581 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 25922 T321 C17 P39581 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3a283a28 lockFactory=org.apache.lucene.store.NativeFSLockFactory@23be23be),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3a283a28 lockFactory=org.apache.lucene.store.NativeFSLockFactory@23be23be),segFN=segments_3,generation=3,filenames=[_0.fnm, _0.nvm, _0.si, segments_3, _0.dvd, _0.pos, _0.fdt, _0.tim, _0.doc, _0.fdx, _0.tip, _0.dvm, _0.nvd]
[junit4:junit4]   2> 25923 T321 C17 P39581 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0.fnm, _0.nvm, _0.si, segments_3, _0.dvd, _0.pos, _0.fdt, _0.tim, _0.doc, _0.fdx, _0.tip, _0.dvm, _0.nvd]
[junit4:junit4]   2> 25925 T321 C17 P39581 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1
[junit4:junit4]   2> 25930 T321 C17 P39581 oass.SolrIndexSearcher.<init> Opening Searcher@66a466a4 main
[junit4:junit4]   2> 25931 T321 C17 P39581 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1/index
[junit4:junit4]   2> 25934 T328 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@66a466a4 main{StandardDirectoryReader(segments_3:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 25935 T328 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1/index
[junit4:junit4]   2> 25936 T321 C17 P39581 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 25937 T321 C17 P39581 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:38370/collection1/, StdNode: http://127.0.0.1:32998/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4]   2> 25940 T350 C16 P38370 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> ASYNC  NEW_CORE C18 name=collection1 org.apache.solr.core.SolrCore@775c775c url=http://127.0.0.1:32998/collection1 node=127.0.0.1:32998_ C18_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:32998, state=active, node_name=127.0.0.1:32998_, collection=collection1, shard=shard2, core=collection1, leader=true}
[junit4:junit4]   2> 25947 T335 C18 P32998 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 25949 T335 C18 P32998 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty2
[junit4:junit4]   2> 25953 T350 C16 P38370 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@71e071e lockFactory=org.apache.lucene.store.NativeFSLockFactory@48d948d9),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@71e071e lockFactory=org.apache.lucene.store.NativeFSLockFactory@48d948d9),segFN=segments_3,generation=3,filenames=[_0.fnm, _0.nvm, _0.si, segments_3, _0.dvd, _0.pos, _0.fdt, _0.tim, _0.doc, _0.fdx, _0.tip, _0.dvm, _0.nvd]
[junit4:junit4]   2> 25954 T350 C16 P38370 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0.fnm, _0.nvm, _0.si, segments_3, _0.dvd, _0.pos, _0.fdt, _0.tim, _0.doc, _0.fdx, _0.tip, _0.dvm, _0.nvd]
[junit4:junit4]   2> 25956 T350 C16 P38370 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3
[junit4:junit4]   2> 25958 T335 C18 P32998 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6de66de6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7d9e7d9e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 25959 T335 C18 P32998 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 25961 T335 C18 P32998 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6de66de6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7d9e7d9e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6de66de6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7d9e7d9e),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 25962 T335 C18 P32998 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 25963 T350 C16 P38370 oass.SolrIndexSearcher.<init> Opening Searcher@a1c0a1c main
[junit4:junit4]   2> 25966 T358 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@a1c0a1c main{StandardDirectoryReader(segments_3:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 25967 T358 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3/index.20130301054950331
[junit4:junit4]   2> 25968 T350 C16 P38370 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 25969 T350 C16 P38370 /update {softCommit=false&expungeDeletes=false&commit_end_point=true&commit=true&version=2&waitSearcher=true&wt=javabin} {commit=} 0 29
[junit4:junit4]   2> 25968 T335 C18 P32998 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty2
[junit4:junit4]   2> 25972 T335 C18 P32998 oass.SolrIndexSearcher.<init> Opening Searcher@612e612e main
[junit4:junit4]   2> 25974 T343 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@612e612e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 25975 T343 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty2/index
[junit4:junit4]   2> 25976 T335 C18 P32998 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 25977 T335 C18 P32998 /update {softCommit=false&expungeDeletes=false&commit_end_point=true&commit=true&version=2&waitSearcher=true&wt=javabin} {commit=} 0 30
[junit4:junit4]   2> 25978 T321 C17 P39581 /update {softCommit=false&commit=true&version=2&waitSearcher=true&wt=javabin} {commit=} 0 63
[junit4:junit4]   2> 25985 T319 C17 P39581 REQ /select {q=*:*&start=0&isShard=true&distrib=false&NOW=1362138593298&fl=id,score&version=2&fsv=true&rows=10&wt=javabin&shard.url=127.0.0.1:39581/collection1/|127.0.0.1:38370/collection1/} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 25986 T334 C18 P32998 REQ /select {q=*:*&start=0&isShard=true&distrib=false&NOW=1362138593298&fl=id,score&version=2&fsv=true&rows=10&wt=javabin&shard.url=127.0.0.1:32998/collection1/} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 26015 T320 C17 P39581 REQ /select {q=*:*&isShard=true&distrib=false&NOW=1362138593298&version=2&ids=1&wt=javabin&shard.url=127.0.0.1:39581/collection1/|127.0.0.1:38370/collection1/} status=0 QTime=4 
[junit4:junit4]   2> 26016 T322 C17 P39581 REQ /select {q=*:*&version=2&wt=javabin} hits=1 status=0 QTime=33 
[junit4:junit4]   2> 26018 T285 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C19 name=onenodecollectioncore org.apache.solr.core.SolrCore@586c586c url=http://127.0.0.1:39581/onenodecollectioncore node=127.0.0.1:39581_ C19_STATE=coll:onenodecollection core:onenodecollectioncore props:{base_url=http://127.0.0.1:39581, state=active, node_name=127.0.0.1:39581_, roles=none, collection=onenodecollection, shard=shard1, core=onenodecollectioncore, leader=true}
[junit4:junit4]   2> 26032 T321 C19 P39581 REQ /select {q=*:*&version=2&wt=javabin} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 26034 T285 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:47063 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@7800780
[junit4:junit4]   2> 26037 T285 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 26038 T368 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:47063. Will not attempt to authenticate using SASL (Access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 26039 T368 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:47063, initiating session
[junit4:junit4]   2> 26039 T287 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:60367
[junit4:junit4]   2> 26040 T287 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:60367
[junit4:junit4]   2> 26041 T289 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d25c9129d000b with negotiated timeout 10000 for client /127.0.0.1:60367
[junit4:junit4]   2> 26041 T368 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:47063, sessionid = 0x13d25c9129d000b, negotiated timeout = 10000
[junit4:junit4]   2> 26042 T369 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7800780 name:ZooKeeperConnection Watcher:127.0.0.1:47063 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 26043 T285 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 collected from various providers and provided free of charge for informational purposes only, with no guarantee whatsoever of accuracy, validity, availability or fitness for any purpose; use at your own risk. Other than that - have fun, and please share/watch/fork if you think data like this should be free!",
[junit4:junit4]   1>           "license": "Data collected from various providers with public-facing APIs; copyright may apply; not for resale; no warranties given.",
[junit4:junit4]   1>           "timestamp": 1332070464,
[junit4:junit4]   1>           "base": "USD",
[junit4:junit4]   1>           "rates": {
[junit4:junit4]   1>             "AED": 3.6732,
[junit4:junit4]   1>             "AFN": 48.299999,
[junit4:junit4]   1>             "ALL": 105.919998,
[junit4:junit4]   1>             "AMD": 388.890015,
[junit4:junit4]   1>             "ANG": 1.79,
[junit4:junit4]   1>             "AOA": 94.769997,
[junit4:junit4]   1>             "ARS": 4.35,
[junit4:junit4]   1>             "AUD": 0.943931,
[junit4:junit4]   1>             "AWG": 1.7899,
[junit4:junit4]   1>             "AZN": 0.7863,
[junit4:junit4]   1>             "BAM": 1.48775,
[junit4:junit4]   1>             "BBD": 2,
[junit4:junit4]   1>             "BDT": 82,
[junit4:junit4]   1>             "BGN": 1.4962,
[junit4:junit4]   1>             "BHD": 0.37703,
[junit4:junit4]   1>             "BIF": 1304.170044,
[junit4:junit4]   1>             "BMD": 1,
[junit4:junit4]   1>             "BND": 1.2575,
[junit4:junit4]   1>             "BOB": 6.91,
[junit4:junit4]   1>             "BRL": 1.8003,
[junit4:junit4]   1>             "BSD": 1,
[junit4:junit4]   1>             "BTN": 50.185001,
[junit4:junit4]   1>             "BWP": 7.2307,
[junit4:junit4]   1>             "BYR": 8150,
[junit4:junit4]   1>             "BZD": 1.9135,
[junit4:junit4]   1>             "CAD": 0.9921,
[junit4:junit4]   1>             "CDF": 917.276917,
[junit4:junit4]   1>             "CHF": 0.9164,
[junit4:junit4]   1>             "CLF": 0.02146,
[junit4:junit4]   1>             "CLP": 482.75,
[junit4:junit4]   1>             "CNY": 6.3239,
[junit4:junit4]   1>             "COP": 1760,
[junit4:junit4]   1>             "CRC": 507.600006,
[junit4:junit4]   1>             "CUP": 1,
[junit4:junit4]   1>             "CVE": 84.190002,
[junit4:junit4]   1>             "CZK": 18.606001,
[junit4:junit4]   1>             "DJF": 179.490005,
[junit4:junit4]   1>             "DKK": 5.64424,
[junit4:junit4]   1>             "DOP": 39.025002,
[junit4:junit4]   1>             "DZD": 74.544998,
[junit4:junit4]   1>             "EGP": 6.0385,
[junit4:junit4]   1>             "ETB": 17.720449,
[junit4:junit4]   1>             "EUR": 0.758956,
[junit4:junit4]   1>             "FJD": 1.7734,
[junit4:junit4]   1>             "FKP": 0.6316,
[junit4:junit4]   1>             "GBP": 0.631373,
[junit4:junit4]   1>             "GEL": 1.6469,
[junit4:junit4]   1>             "GHS": 1.7455,
[junit4:junit4]   1>             "GIP": 0.63165,
[junit4:junit4]   1>             "GMD": 31.5,
[junit4:junit4]   1>             "GNF": 7100,
[junit4:junit4]   1>             "GTQ": 7.6975,
[junit4:junit4]   1>             "GYD": 203.699997,
[junit4:junit4]   1>             "HKD": 7.76306,
[junit4:junit4]   1>             "HNL": 19.055,
[junit4:junit4]   1>             "HRK": 5.7333,
[junit4:junit4]   1>             "HTG": 41,
[junit4:junit4]   1>             "HUF": 219.850006,
[junit4:junit4]   1>             "IDR": 9118,
[junit4:junit4]   1>             "IEP": 0.5978,
[junit4:junit4]   1>             "ILS": 3.7542,
[junit4:junit4]   1>             "INR": 50.165001,
[junit4:junit4]   1>             "IQD": 1165.5,
[junit4:junit4]   1>             "IRR": 12308,
[junit4:junit4]   1>             "ISK": 127.440002,
[junit4:junit4]   1>             "JMD": 86.699997,
[junit4:junit4]   1>             "JOD": 0.7095,
[junit4:junit4]   1>             "JPY": 83.445,
[junit4:junit4]   1>             "KES": 83.18,
[junit4:junit4]   1>             "KGS": 46.699402,
[junit4:junit4]   1>             "KHR": 4010.300049,
[junit4:junit4]   1>             "KMF": 373.424255,
[junit4:junit4]   1>             "KPW": 900,
[junit4:junit4]   1>             "KRW": 1125.849976,
[junit4:junit4]   1>             "KWD": 0.27925,
[junit4:junit4]   1>             "KZT": 147.690002,
[junit4:junit4]   1>             "LAK": 7993.799805,
[junit4:junit4]   1>             "LBP": 1504,
[junit4:junit4]   1>             "LKR": 125.224998,
[junit4:junit4]   1>             "LRD": 73.459999,
[junit4:junit4]   1>             "LSL": 7.5768,
[junit4:junit4]   1>             "LTL": 2.6219,
[junit4:junit4]   1>             "LVL": 0.5291,
[junit4:junit4]   1>             "LYD": 1.2572,
[junit4:junit4]   1>             "MAD": 8.4611,
[junit4:junit4]   1>             "MDL": 11.89,
[junit4:junit4]   1>             "MGA": 2155,
[junit4:junit4]   1>             "MKD": 46.705002,
[junit4:junit4]   1>             "MMK": 6.51,
[junit4:junit4]   1>             "MNT": 1322.5,
[junit4:junit4]   1>             "MOP": 7.9958,
[junit4:junit4]   1>             "MRO": 293,
[junit4:junit4]   1>             "MUR": 29.110001,
[junit4:junit4]   1>             "MVR": 15.36,
[junit4:junit4]   1>             "MWK": 165.206207,
[junit4:junit4]   1>             "MXN": 12.6745,
[junit4:junit4]   1>             "MYR": 3.0575,
[junit4:junit4]   1>             "MZN": 27.200001,
[junit4:junit4]   1>             "NAD": 7.58,
[junit4:junit4]   1>             "NGN": 157.600006,
[junit4:junit4]   1>             "NIO": 23.215,
[junit4:junit4]   1>             "NOK": 5.73163,
[junit4:junit4]   1>             "NPR": 80.620003,
[junit4:junit4]   1>             "NZD": 1.212269,
[junit4:junit4]   1>             "OMR": 0.38485,
[junit4:junit4]   1>             "PAB": 1,
[junit4:junit4]   1>             "PEN": 2.674,
[junit4:junit4]   1>             "PGK": 2.0627,
[junit4:junit4]   1>             "PHP": 43.02,
[junit4:junit4]   1>             "PKR": 90.800003,
[junit4:junit4]   1>             "PLN": 3.1285,
[junit4:junit4]   1>             "PYG": 4245,
[junit4:junit4]   1>             "QAR": 3.6415,
[junit4:junit4]   1>             "RON": 3.3256,
[junit4:junit4]   1>             "RSD": 84.100502,
[junit4:junit4]   1>             "RUB": 29.2342,
[junit4:junit4]   1>             "RWF": 606.717468,
[junit4:junit4]   1>             "SAR": 3.7505,
[junit4:junit4]   1>             "SBD": 7.075973,
[junit4:junit4]   1>             "SCR": 14.0447,
[junit4:junit4]   1>             "SDG": 2.6765,
[junit4:junit4]   1>             "SEK": 6.74525,
[junit4:junit4]   1>             "SGD": 1.258,
[junit4:junit4]   1>             "SHP": 0.63165,
[junit4:junit4]   1>             "SLL": 4364.5,
[junit4:junit4]   1>             "SOS": 1629,
[junit4:junit4]   1>             "SRD": 3.2875,
[junit4:junit4]   1>             "STD": 18650,
[junit4:junit4]   1>             "SVC": 8.7475,
[junit4:junit4]   1>             "SYP": 57.450001,
[junit4:junit4]   1>             "SZL": 7.5752,
[junit4:junit4]   1>             "THB": 30.700001,
[junit4:junit4]   1>             "TJS": 4.7588,
[junit4:junit4]   1>             "TMT": 2.85,
[junit4:junit4]   1>             "TND": 1.5178,
[junit4:junit4]   1>             "TOP": 1.693601,
[junit4:junit4]   1>             "TRY": 1.796,
[junit4:junit4]   1>             "TTD": 6.40015,
[junit4:junit4]   1>             "TWD": 29.532,
[junit4:junit4]   1>             "TZS": 1595,
[junit4:junit4]   1>             "UAH": 8.029,
[junit4:junit4]   1>             "UGX": 2481.699951,
[junit4:junit4]   1>             "USD": 1,
[junit4:junit4]   1>             "UYU": 19.469999,
[junit4:junit4]   1>             "UZS": 1835.75,
[junit4:junit4]   1>             "VEF": 4.295,
[junit4:junit4]   1>             "VND": 20820,
[junit4:junit4]   1>             "VUV": 90.199997,
[junit4:junit4]   1>             "WST": 2.247475,
[junit4:junit4]   1>             "XAF": 497.898987,
[junit4:junit4]   1>             "XCD": 2.7,
[junit4:junit4]   1>             "XDR": 0.652794,
[junit4:junit4]   1>             "XOF": 498.399994,
[junit4:junit4]   1>             "XPF": 90.639999,
[junit4:junit4]   1>             "YER": 216.005005,
[junit4:junit4]   1>             "ZAR": 7.5688,
[junit4:junit4]   1>             "ZMK": 5271.5,
[junit4:junit4]   1>             "ZWD": 378.700012,
[junit4:junit4]   1>             "ZWL": 322.355011
[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":"89269113148211203-127.0.0.1:50292_-n_0000000000"}
[junit4:junit4]   1>    /solr/overseer_elect/election (4)
[junit4:junit4]   1>     /solr/overseer_elect/election/89269113148211206-127.0.0.1:39581_-n_0000000001 (0)
[junit4:junit4]   1>     /solr/overseer_elect/election/89269113148211210-127.0.0.1:38370_-n_0000000003 (0)
[junit4:junit4]   1>     /solr/overseer_elect/election/89269113148211208-127.0.0.1:32998_-n_0000000002 (0)
[junit4:junit4]   1>     /solr/overseer_elect/election/89269113148211203-127.0.0.1:50292_-n_0000000000 (0)
[junit4:junit4]   1>   /solr/overseer (3)
[junit4:junit4]   1>   DATA:
[junit4:junit4]   1>       
[junit4:junit4]   1>    /solr/overseer/queue (0)
[junit4:junit4]   1>    DATA:
[junit4:junit4]   1>        
[junit4:junit4]   1>    /solr/overseer/collection-queue-work (0)
[junit4:junit4]   1>    DATA:
[junit4:junit4]   1>        
[junit4:junit4]   1>    /solr/overseer/queue-work (0)
[junit4:junit4]   1>    DATA:
[junit4:junit4]   1>        
[junit4:junit4]   1>   /solr/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/89269113148211203-127.0.0.1:50292__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:50292",
[junit4:junit4]   1>            "node_name":"127.0.0.1:50292_",
[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/89269113148211206-127.0.0.1:39581__collection1-n_0000000000 (0)
[junit4:junit4]   1>        /solr/collections/collection1/leader_elect/shard1/election/89269113148211210-127.0.0.1:38370__collection1-n_0000000001 (0)
[junit4:junit4]   1>      /solr/collections/collection1/leader_elect/shard2 (1)
[junit4:junit4]   1>       /solr/collections/collection1/leader_elect/shard2/election (1)
[junit4:junit4]   1>        /solr/collections/collection1/leader_elect/shard2/election/89269113148211208-127.0.0.1:32998__collection1-n_0000000000 (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:39581",
[junit4:junit4]   1>            "node_name":"127.0.0.1:39581_",
[junit4:junit4]   1>            "core":"collection1"}
[junit4:junit4]   2> 26127 T290 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d25c9129d000b
[junit4:junit4]   2> 26128 T287 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:60367 which had sessionid 0x13d25c9129d000b
[junit4:junit4]   2> 26129 T369 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 26128 T285 oaz.ZooKeeper.close Session: 0x13d25c9129d000b closed
[junit4:junit4]   2> 26130 T290 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d25c9129d0004
[junit4:junit4]   2> 26131 T287 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:60340 which had sessionid 0x13d25c9129d0004
[junit4:junit4]   2> 26131 T313 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 26131 T285 oaz.ZooKeeper.close Session: 0x13d25c9129d0004 closed
[junit4:junit4]   2> 26137 T285 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 50292
[junit4:junit4]   2> 26138 T285 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1070874580
[junit4:junit4]   2> 26860 T308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 26861 T308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50292",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:50292__collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50292_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "core":"collection1"}
[junit4:junit4]   2> 26916 T307 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> 26916 T356 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> 26916 T326 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> 26916 T341 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> 28140 T285 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@5cf85cf8
[junit4:junit4]   2> 28146 T285 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3/index.20130301054950331
[junit4:junit4]   2> 28148 T285 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3
[junit4:junit4]   2> 28152 T285 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 28153 T285 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 28154 T285 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 28155 T285 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 28156 T285 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 28157 T285 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/control/data/index
[junit4:junit4]   2> 28157 T285 oasc.CachingDirectoryFactory.close Closing directory when closing factory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/control/data/index
[junit4:junit4]   2> 28158 T285 oasc.CachingDirectoryFactory.closeDirectory Closing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/control/data/index
[junit4:junit4]   2> 28159 T285 oasc.CachingDirectoryFactory.close Closing directory when closing factory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/control/data
[junit4:junit4]   2> 28159 T285 oasc.CachingDirectoryFactory.closeDirectory Closing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/control/data
[junit4:junit4]   2> 28160 T308 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89269113148211203-127.0.0.1:50292_-n_0000000000) am no longer a leader.
[junit4:junit4]   2> 28160 T290 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d25c9129d0003
[junit4:junit4]   2> 28162 T356 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> 28162 T341 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> 28162 T287 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:60338 which had sessionid 0x13d25c9129d0003
[junit4:junit4]   2> 28162 T307 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> 28163 T285 oaz.ZooKeeper.close Session: 0x13d25c9129d0003 closed
[junit4:junit4]   2> 28164 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0006 type:delete cxid:0xb9 zxid:0xcd txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 28165 T307 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 28166 T307 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 28166 T326 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 28167 T307 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 28167 T341 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 28167 T356 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 28200 T326 oasc.Overseer.start Overseer (id=89269113148211206-127.0.0.1:39581_-n_0000000001) starting
[junit4:junit4]   2> 28201 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0006 type:create cxid:0xbe zxid:0xcf txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 28202 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0006 type:create cxid:0xbf zxid:0xd0 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 28203 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0006 type:create cxid:0xc0 zxid:0xd1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 28204 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0006 type:create cxid:0xc1 zxid:0xd2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 28205 T371 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 28207 T326 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 28208 T326 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> 28209 T370 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 28209 T285 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4]   2> 28261 T285 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 39581
[junit4:junit4]   2> 28262 T285 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=83035379
[junit4:junit4]   2> 29715 T370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 29717 T370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:39581",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:39581__onenodecollectioncore",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:39581_",
[junit4:junit4]   2> 	  "roles":"none",
[junit4:junit4]   2> 	  "collection":"onenodecollection",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "core":"onenodecollectioncore"}
[junit4:junit4]   2> 29722 T370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:39581",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:39581__collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:39581_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "core":"collection1"}
[junit4:junit4]   2> 29728 T356 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> 29728 T326 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> 29728 T341 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> 31266 T285 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@2a3f2a3f
[junit4:junit4]   2> 31269 T285 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3/index.20130301054950331
[junit4:junit4]   2> 31270 T285 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3
[junit4:junit4]   2> 31272 T285 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=2,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=1,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 31273 T285 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 31274 T285 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 31274 T285 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2>  C17_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:39581, state=down, node_name=127.0.0.1:39581_, collection=collection1, shard=shard1, core=collection1, leader=true}
[junit4:junit4]   2> 31276 T285 C17 P39581 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1/index
[junit4:junit4]   2> 31276 T285 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 31277 T285 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1/index
[junit4:junit4]   2> 31277 T285 oasc.CachingDirectoryFactory.close Closing directory when closing factory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1
[junit4:junit4]   2> 31278 T285 oasc.CachingDirectoryFactory.closeDirectory Closing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1
[junit4:junit4]   2> 31278 T285 oasc.CachingDirectoryFactory.close Closing directory when closing factory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1/index
[junit4:junit4]   2> 31279 T285 oasc.CachingDirectoryFactory.closeDirectory Closing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty1/index
[junit4:junit4]   2> 31279 T285 oasc.SolrCore.close [onenodecollectioncore]  CLOSING SolrCore org.apache.solr.core.SolrCore@586c586c
[junit4:junit4]   2> 31287 T285 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 31288 T285 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 31288 T285 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 31289 T285 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 31290 T285 oasc.SolrCore.closeSearcher [onenodecollectioncore] Closing main searcher on request.
[junit4:junit4]   2> 31290 T285 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362138567320/onenodecollection/index
[junit4:junit4]   2> 31291 T285 oasc.CachingDirectoryFactory.close Closing directory when closing factory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362138567320/onenodecollection/index
[junit4:junit4]   2> 31291 T285 oasc.CachingDirectoryFactory.closeDirectory Closing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362138567320/onenodecollection/index
[junit4:junit4]   2> 31292 T285 oasc.CachingDirectoryFactory.close Closing directory when closing factory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362138567320/onenodecollection
[junit4:junit4]   2> 31292 T285 oasc.CachingDirectoryFactory.closeDirectory Closing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362138567320/onenodecollection
[junit4:junit4]   2> 31293 T370 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89269113148211206-127.0.0.1:39581_-n_0000000001) am no longer a leader.
[junit4:junit4]   2> 31294 T290 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d25c9129d0006
[junit4:junit4]   2> 31304 T356 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> 31304 T287 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:60342 which had sessionid 0x13d25c9129d0006
[junit4:junit4]   2> 31305 T285 oaz.ZooKeeper.close Session: 0x13d25c9129d0006 closed
[junit4:junit4]   2> 31307 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0008 type:delete cxid:0x6e zxid:0xdd txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 31308 T341 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 31309 T356 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 31311 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d000a type:delete cxid:0x56 zxid:0xdf txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard1 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard1
[junit4:junit4]   2> 31312 T356 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 31313 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d000a type:create cxid:0x57 zxid:0xe0 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 31313 T341 oasc.Overseer.start Overseer (id=89269113148211208-127.0.0.1:32998_-n_0000000002) starting
[junit4:junit4]   2> 31315 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0008 type:create cxid:0x73 zxid:0xe1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 31317 T356 oasc.ShardLeaderElectionContext.shouldIBeLeader Checking if I should try and be the leader.
[junit4:junit4]   2> 31317 T356 oasc.ShardLeaderElectionContext.shouldIBeLeader My last published State was Active, it's okay to be the leader.
[junit4:junit4]   2> 31318 T356 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 31318 T356 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:38370/collection1/
[junit4:junit4]   2> 31318 T356 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 31319 T356 oasc.SyncStrategy.syncToMe http://127.0.0.1:38370/collection1/ has no replicas
[junit4:junit4]   2> 31319 T356 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:38370/collection1/
[junit4:junit4]   2> 31320 T356 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 31321 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0008 type:create cxid:0x74 zxid:0xe3 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 31322 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0008 type:create cxid:0x75 zxid:0xe4 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 31325 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d0008 type:create cxid:0x76 zxid:0xe5 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 31326 T341 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> 31326 T373 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 31330 T285 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4]   2> 31333 T290 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d25c9129d000a type:create cxid:0x5f zxid:0xe7 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 31334 T341 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 31336 T372 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 31341 T372 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 31353 T341 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> 31353 T356 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> 31383 T285 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 32998
[junit4:junit4]   2> 31384 T285 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1103118784
[junit4:junit4]   2> 32386 T285 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@775c775c
[junit4:junit4]   2> 32390 T285 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3/index.20130301054950331
[junit4:junit4]   2> 32391 T285 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty3
[junit4:junit4]   2> 32396 T285 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 32397 T285 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 32397 T285 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 32398 T285 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 32400 T285 C18 P32998 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty2/index
[junit4:junit4]   2> 32401 T285 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 32401 T285 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty2/index
[junit4:junit4]   2> 32402 T285 oasc.CachingDirectoryFactory.close Closing directory when closing factory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty2
[junit4:junit4]   2> 32402 T285 oasc.CachingDirectoryFactory.closeDirectory Closing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362138567320/jetty2
[junit4:junit4]   2> 32403 T285 oasc.CachingDirectoryFactory.close Closing directory when closing factory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2

[...truncated too long message...]

",
[junit4:junit4]   1>                   "collection":"collection1",
[junit4:junit4]   1>                   "shard":"shard1",
[junit4:junit4]   1>                   "core":"collection1",
[junit4:junit4]   1>                   "leader":"true"},
[junit4:junit4]   1>                 "127.0.0.1:38370__collection1":{
[junit4:junit4]   1>                   "base_url":"http://127.0.0.1:38370",
[junit4:junit4]   1>                   "state":"active",
[junit4:junit4]   1>                   "node_name":"127.0.0.1:38370_",
[junit4:junit4]   1>                   "collection":"collection1",
[junit4:junit4]   1>                   "shard":"shard1",
[junit4:junit4]   1>                   "core":"collection1"}}},
[junit4:junit4]   1>             "shard2":{
[junit4:junit4]   1>               "range":"0-7fffffff",
[junit4:junit4]   1>               "state":"active",
[junit4:junit4]   1>               "replicas":{"127.0.0.1:32998__collection1":{
[junit4:junit4]   1>                   "base_url":"http://127.0.0.1:32998",
[junit4:junit4]   1>                   "state":"active",
[junit4:junit4]   1>                   "node_name":"127.0.0.1:32998_",
[junit4:junit4]   1>                   "collection":"collection1",
[junit4:junit4]   1>                   "shard":"shard2",
[junit4:junit4]   1>                   "core":"collection1",
[junit4:junit4]   1>                   "leader":"true"}}}},
[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=C2EE8FAB9556DC53 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ar_TN -Dtests.timezone=America/Bahia_Banderas -Dtests.file.encoding=UTF-8
[junit4:junit4] FAILURE 33.6s J1 | BasicDistributedZk2Test.testDistribSearch <<<
[junit4:junit4]    > Throwable #1: java.lang.AssertionError: expected:<1> but was:<0>
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([C2EE8FAB9556DC53:430801B3E209BC6F]:0)
[junit4:junit4]    > 	at org.junit.Assert.fail(Assert.java:93)
[junit4:junit4]    > 	at org.junit.Assert.failNotEquals(Assert.java:647)
[junit4:junit4]    > 	at org.junit.Assert.assertEquals(Assert.java:128)
[junit4:junit4]    > 	at org.junit.Assert.assertEquals(Assert.java:472)
[junit4:junit4]    > 	at org.junit.Assert.assertEquals(Assert.java:456)
[junit4:junit4]    > 	at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:209)
[junit4:junit4]    > 	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:89)
[junit4:junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java: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> 33651 T285 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> 33664 T284 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4]   2> 33685 T288 oazs.SessionTrackerImpl.run SessionTrackerImpl exited loop!
[junit4:junit4]   2> 34818 T356 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 34819 T356 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 34819 T356 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=ar_TN, timezone=America/Bahia_Banderas
[junit4:junit4]   2> NOTE: Linux 3.2.0-38-generic x86/IBM Corporation 1.6.0 (32-bit)/cpus=8,threads=1,free=18228272,total=50256384
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestAtomicUpdateErrorCases, TestHashPartitioner, TestDistributedSearch, RecoveryZkTest, BasicFunctionalityTest, BasicDistributedZk2Test]
[junit4:junit4] Completed on J1 in 34.95s, 1 test, 1 failure <<< FAILURES!

[...truncated 651 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:381: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:374: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:183: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:449: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1207: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:870: There were test failures: 257 suites, 1075 tests, 1 failure, 9 ignored (4 assumptions)

Total time: 49 minutes 30 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



Mime
View raw message