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-Windows (64bit/jdk1.7.0_15) - Build # 2617 - Failure!
Date Mon, 04 Mar 2013 16:01:01 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/2617/
Java: 64bit/jdk1.7.0_15 -XX:+UseG1GC

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

Error Message:
No registered leader was found, collection:collection1 slice:shard1

Stack Trace:
org.apache.solr.common.SolrException: No registered leader was found, collection:collection1 slice:shard1
	at __randomizedtesting.SeedInfo.seed([AFDBFC76F220D69E:2E3D726E857FB6A2]:0)
	at org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:430)
	at org.apache.solr.cloud.BasicDistributedZk2Test.brindDownShardIndexSomeDocsAndRecover(BasicDistributedZk2Test.java:295)
	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:116)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:722)




Build Log:
[...truncated 8855 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 0 T268 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4]   2> 7 T268 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-BasicDistributedZk2Test-1362410891798
[junit4:junit4]   2> 9 T268 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 10 T269 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 15 T269 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 15 T269 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4]   2> 15 T269 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4]   2> 17 T269 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 18 T269 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\zookeeper\server1\data\version-2\snapshot.0
[junit4:junit4]   2> 110 T268 oasc.ZkTestServer.run start zk server on port:54603
[junit4:junit4]   2> 110 T268 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54603 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@6563aac7
[junit4:junit4]   2> 112 T268 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 114 T274 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54603. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 115 T274 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54603, initiating session
[junit4:junit4]   2> 115 T270 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54606
[junit4:junit4]   2> 116 T270 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54606
[junit4:junit4]   2> 116 T272 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 123 T272 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d36046a210000 with negotiated timeout 10000 for client /127.0.0.1:54606
[junit4:junit4]   2> 123 T274 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54603, sessionid = 0x13d36046a210000, negotiated timeout = 10000
[junit4:junit4]   2> 124 T275 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6563aac7 name:ZooKeeperConnection Watcher:127.0.0.1:54603 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 125 T268 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 125 T268 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 131 T273 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d36046a210000
[junit4:junit4]   2> 133 T275 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 134 T270 oazs.NIOServerCnxn.doIO WARNING caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13d36046a210000, likely client has closed socket
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4]   2> 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 
[junit4:junit4]   2> 135 T270 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:54606 which had sessionid 0x13d36046a210000
[junit4:junit4]   2> 134 T268 oaz.ZooKeeper.close Session: 0x13d36046a210000 closed
[junit4:junit4]   2> 136 T268 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54603/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@298fb79f
[junit4:junit4]   2> 137 T268 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 138 T276 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54603. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 139 T276 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54603, initiating session
[junit4:junit4]   2> 140 T270 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54609
[junit4:junit4]   2> 140 T270 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54609
[junit4:junit4]   2> 142 T272 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d36046a210001 with negotiated timeout 10000 for client /127.0.0.1:54609
[junit4:junit4]   2> 142 T276 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54603, sessionid = 0x13d36046a210001, negotiated timeout = 10000
[junit4:junit4]   2> 143 T277 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@298fb79f name:ZooKeeperConnection Watcher:127.0.0.1:54603/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 143 T268 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 144 T268 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 152 T268 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 160 T268 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 172 T268 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 182 T268 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 183 T268 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 195 T268 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 196 T268 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 204 T268 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 205 T268 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 212 T268 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 212 T268 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 220 T268 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 220 T268 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 227 T268 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 228 T268 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 244 T268 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 245 T268 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 253 T268 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 254 T268 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 261 T268 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 261 T268 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 269 T273 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d36046a210001
[junit4:junit4]   2> 271 T277 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 272 T270 oazs.NIOServerCnxn.doIO WARNING caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13d36046a210001, likely client has closed socket
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4]   2> 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 
[junit4:junit4]   2> 271 T268 oaz.ZooKeeper.close Session: 0x13d36046a210001 closed
[junit4:junit4]   2> 272 T270 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:54609 which had sessionid 0x13d36046a210001
[junit4:junit4]   2> 637 T268 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 655 T268 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54610
[junit4:junit4]   2> 656 T268 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 657 T268 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 657 T268 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362410892063
[junit4:junit4]   2> 657 T268 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362410892063\solr.xml
[junit4:junit4]   2> 657 T268 oasc.CoreContainer.<init> New CoreContainer 2073642531
[junit4:junit4]   2> 658 T268 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362410892063\'
[junit4:junit4]   2> 658 T268 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362410892063\'
[junit4:junit4]   2> 711 T268 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 712 T268 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 712 T268 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 712 T268 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 713 T268 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 713 T268 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 713 T268 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 714 T268 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 714 T268 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 714 T268 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 731 T268 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 752 T268 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:54603/solr
[junit4:junit4]   2> 753 T268 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 753 T268 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54603 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@158c423
[junit4:junit4]   2> 755 T268 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 756 T287 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54603. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 757 T287 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54603, initiating session
[junit4:junit4]   2> 757 T270 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54615
[junit4:junit4]   2> 758 T270 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54615
[junit4:junit4]   2> 773 T272 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d36046a210002 with negotiated timeout 20000 for client /127.0.0.1:54615
[junit4:junit4]   2> 773 T287 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54603, sessionid = 0x13d36046a210002, negotiated timeout = 20000
[junit4:junit4]   2> 773 T288 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@158c423 name:ZooKeeperConnection Watcher:127.0.0.1:54603 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 774 T268 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 776 T273 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d36046a210002
[junit4:junit4]   2> 793 T268 oaz.ZooKeeper.close Session: 0x13d36046a210002 closed
[junit4:junit4]   2> 794 T288 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 794 T270 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:54615 which had sessionid 0x13d36046a210002
[junit4:junit4]   2> 794 T268 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 801 T268 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54603/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@6af7033c
[junit4:junit4]   2> 804 T268 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 805 T289 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54603. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 806 T289 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54603, initiating session
[junit4:junit4]   2> 806 T270 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54618
[junit4:junit4]   2> 806 T270 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54618
[junit4:junit4]   2> 810 T272 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d36046a210003 with negotiated timeout 20000 for client /127.0.0.1:54618
[junit4:junit4]   2> 810 T289 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54603, sessionid = 0x13d36046a210003, negotiated timeout = 20000
[junit4:junit4]   2> 810 T290 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6af7033c name:ZooKeeperConnection Watcher:127.0.0.1:54603/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 811 T268 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 816 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 819 T268 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 824 T268 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54610_
[junit4:junit4]   2> 825 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:54610_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:54610_
[junit4:junit4]   2> 827 T268 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54610_
[junit4:junit4]   2> 835 T268 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 847 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210003 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> 850 T268 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 857 T268 oasc.Overseer.start Overseer (id=89286960205594627-127.0.0.1:54610_-n_0000000000) starting
[junit4:junit4]   2> 858 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 859 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 862 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 865 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 873 T268 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 876 T292 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 904 T268 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 935 T291 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 942 T293 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362410892063\collection1
[junit4:junit4]   2> 942 T293 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 943 T293 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 943 T293 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 945 T293 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362410892063\collection1\'
[junit4:junit4]   2> 946 T293 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362410892063/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 947 T293 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362410892063/collection1/lib/README' to classloader
[junit4:junit4]   2> 1030 T293 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 1095 T293 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 1098 T293 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 1104 T293 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1823 T293 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1835 T293 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1839 T293 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1864 T293 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1871 T293 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1878 T293 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1880 T293 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 1880 T293 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 1880 T293 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1883 T293 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 1883 T293 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 1883 T293 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362410892063\collection1\, dataDir=.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797/control/data\
[junit4:junit4]   2> 1883 T293 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b4fb007
[junit4:junit4]   2> 1884 T293 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 1885 T293 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\control\data forceNew:false
[junit4:junit4]   2> 1885 T293 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\control\data
[junit4:junit4]   2> 1885 T293 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797/control/data\index/
[junit4:junit4]   2> 1886 T293 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\control\data\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1886 T293 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\control\data\index forceNew:false
[junit4:junit4]   2> 1891 T293 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2d1415e6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3110ae99),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1891 T293 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 1893 T293 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\control\data\index
[junit4:junit4]   2> 1942 T293 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1943 T293 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1943 T293 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1943 T293 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1944 T293 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1944 T293 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1944 T293 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1945 T293 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1945 T293 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1956 T293 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1963 T293 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\control\data
[junit4:junit4]   2> 1964 T293 oass.SolrIndexSearcher.<init> Opening Searcher@d535d91 main
[junit4:junit4]   2> 1970 T293 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\control\data\tlog
[junit4:junit4]   2> 1988 T293 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1989 T293 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1994 T293 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\control\data
[junit4:junit4]   2> 1995 T294 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@d535d91 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1996 T293 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 1997 T293 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1998 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210003 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> 2443 T291 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2443 T291 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"1",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54610_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54610"}
[junit4:junit4]   2> 2443 T291 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 2447 T291 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 2448 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210003 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> 2465 T290 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> 3026 T293 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 3026 T293 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54610 collection:control_collection shard:shard1
[junit4:junit4]   2> 3028 T293 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 3066 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210003 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> 3068 T293 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 3068 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210003 type:create cxid:0x73 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3076 T293 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 3076 T293 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 3077 T293 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54610/collection1/
[junit4:junit4]   2> 3078 T293 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 3078 T293 oasc.SyncStrategy.syncToMe http://127.0.0.1:54610/collection1/ has no replicas
[junit4:junit4]   2> 3078 T293 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54610/collection1/
[junit4:junit4]   2> 3079 T293 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 3091 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210003 type:create cxid:0x7d zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3974 T291 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4061 T290 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> 4112 T293 oasc.ZkController.register We are http://127.0.0.1:54610/collection1/ and leader is http://127.0.0.1:54610/collection1/
[junit4:junit4]   2> 4118 T293 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54610
[junit4:junit4]   2> 4118 T293 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 4119 T293 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 4120 T293 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 4143 T293 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4145 T268 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 4145 T268 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 4146 T268 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 4161 T268 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 4165 T268 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54603/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@2930574
[junit4:junit4]   2> 4168 T268 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4169 T296 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54603. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 4169 T296 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54603, initiating session
[junit4:junit4]   2> 4170 T270 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54621
[junit4:junit4]   2> 4170 T270 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54621
[junit4:junit4]   2> 4173 T272 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d36046a210004 with negotiated timeout 10000 for client /127.0.0.1:54621
[junit4:junit4]   2> 4173 T296 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54603, sessionid = 0x13d36046a210004, negotiated timeout = 10000
[junit4:junit4]   2> 4174 T297 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2930574 name:ZooKeeperConnection Watcher:127.0.0.1:54603/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4174 T268 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4183 T268 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4190 T268 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 4569 T268 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 4572 T268 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54622
[junit4:junit4]   2> 4573 T268 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 4575 T268 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4575 T268 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362410895980
[junit4:junit4]   2> 4575 T268 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362410895980\solr.xml
[junit4:junit4]   2> 4575 T268 oasc.CoreContainer.<init> New CoreContainer 186850364
[junit4:junit4]   2> 4576 T268 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362410895980\'
[junit4:junit4]   2> 4576 T268 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362410895980\'
[junit4:junit4]   2> 4630 T268 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 4631 T268 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 4631 T268 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 4632 T268 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 4632 T268 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 4633 T268 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 4633 T268 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 4633 T268 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 4634 T268 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 4634 T268 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 4649 T268 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 4669 T268 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:54603/solr
[junit4:junit4]   2> 4670 T268 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 4670 T268 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54603 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@5c00e819
[junit4:junit4]   2> 4672 T268 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4673 T307 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54603. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 4674 T307 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54603, initiating session
[junit4:junit4]   2> 4674 T270 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54627
[junit4:junit4]   2> 4674 T270 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54627
[junit4:junit4]   2> 4695 T272 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d36046a210005 with negotiated timeout 20000 for client /127.0.0.1:54627
[junit4:junit4]   2> 4695 T307 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54603, sessionid = 0x13d36046a210005, negotiated timeout = 20000
[junit4:junit4]   2> 4696 T308 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c00e819 name:ZooKeeperConnection Watcher:127.0.0.1:54603 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4696 T268 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4698 T273 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d36046a210005
[junit4:junit4]   2> 4709 T308 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 4709 T270 oazs.NIOServerCnxn.doIO WARNING caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13d36046a210005, likely client has closed socket
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4]   2> 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 
[junit4:junit4]   2> 4709 T268 oaz.ZooKeeper.close Session: 0x13d36046a210005 closed
[junit4:junit4]   2> 4711 T270 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:54627 which had sessionid 0x13d36046a210005
[junit4:junit4]   2> 4711 T268 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 4717 T268 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54603/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@4ddeb89b
[junit4:junit4]   2> 4718 T268 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4720 T309 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54603. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 4720 T309 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54603, initiating session
[junit4:junit4]   2> 4721 T270 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54630
[junit4:junit4]   2> 4721 T270 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54630
[junit4:junit4]   2> 4739 T272 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d36046a210006 with negotiated timeout 20000 for client /127.0.0.1:54630
[junit4:junit4]   2> 4739 T309 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54603, sessionid = 0x13d36046a210006, negotiated timeout = 20000
[junit4:junit4]   2> 4739 T310 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ddeb89b name:ZooKeeperConnection Watcher:127.0.0.1:54603/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4740 T268 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4741 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210006 type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4760 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210006 type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4782 T268 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 5606 T291 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5607 T291 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"1",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54610_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54610"}
[junit4:junit4]   2> 5621 T297 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> 5623 T290 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> 5623 T310 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> 5787 T268 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54622_
[junit4:junit4]   2> 5788 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210006 type:delete cxid:0xb zxid:0x4f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:54622_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:54622_
[junit4:junit4]   2> 5792 T268 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54622_
[junit4:junit4]   2> 5797 T290 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> 5798 T297 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5798 T297 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> 5799 T310 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5799 T310 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> 5808 T290 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5818 T311 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362410895980\collection1
[junit4:junit4]   2> 5818 T311 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 5820 T311 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 5820 T311 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 5823 T311 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362410895980\collection1\'
[junit4:junit4]   2> 5823 T311 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362410895980/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 5825 T311 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362410895980/collection1/lib/README' to classloader
[junit4:junit4]   2> 5876 T311 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 5966 T311 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 5969 T311 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 5974 T311 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 6655 T311 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 6670 T311 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 6675 T311 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 6706 T311 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6713 T311 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6720 T311 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6723 T311 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 6724 T311 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 6724 T311 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6726 T311 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 6726 T311 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 6726 T311 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362410895980\collection1\, dataDir=.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797/jetty1\
[junit4:junit4]   2> 6726 T311 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b4fb007
[junit4:junit4]   2> 6726 T311 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 6726 T311 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty1 forceNew:false
[junit4:junit4]   2> 6726 T311 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty1
[junit4:junit4]   2> 6726 T311 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797/jetty1\index/
[junit4:junit4]   2> 6726 T311 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 6726 T311 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty1\index forceNew:false
[junit4:junit4]   2> 6730 T311 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5022ac3e lockFactory=org.apache.lucene.store.NativeFSLockFactory@3208a6c4),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 6730 T311 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 6732 T311 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty1\index
[junit4:junit4]   2> 6734 T311 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 6734 T311 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 6735 T311 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 6735 T311 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 6737 T311 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 6737 T311 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 6737 T311 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 6738 T311 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 6738 T311 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 6748 T311 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 6755 T311 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty1
[junit4:junit4]   2> 6755 T311 oass.SolrIndexSearcher.<init> Opening Searcher@431d2459 main
[junit4:junit4]   2> 6756 T311 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty1\tlog
[junit4:junit4]   2> 6757 T311 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 6757 T311 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 6762 T311 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty1
[junit4:junit4]   2> 6764 T311 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 6765 T311 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 6767 T312 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@431d2459 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 7134 T291 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7136 T291 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"2",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54622_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54622"}
[junit4:junit4]   2> 7136 T291 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4]   2> 7136 T291 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 7150 T297 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> 7150 T310 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> 7150 T290 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> 7772 T311 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 7772 T311 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54622 collection:collection1 shard:shard1
[junit4:junit4]   2> 7774 T311 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 7792 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210006 type:delete cxid:0x48 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 7794 T311 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 7795 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210006 type:create cxid:0x49 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7801 T311 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 7801 T311 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 7801 T311 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54622/collection1/
[junit4:junit4]   2> 7802 T311 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 7802 T311 oasc.SyncStrategy.syncToMe http://127.0.0.1:54622/collection1/ has no replicas
[junit4:junit4]   2> 7802 T311 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54622/collection1/
[junit4:junit4]   2> 7803 T311 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 7813 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210006 type:create cxid:0x53 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8747 T291 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8832 T290 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> 8833 T310 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> 8833 T297 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> 8880 T311 oasc.ZkController.register We are http://127.0.0.1:54622/collection1/ and leader is http://127.0.0.1:54622/collection1/
[junit4:junit4]   2> 8880 T311 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54622
[junit4:junit4]   2> 8880 T311 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 8881 T311 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 8881 T311 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 8898 T311 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8900 T268 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 8900 T268 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 8901 T268 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 9307 T268 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 9312 T268 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54631
[junit4:junit4]   2> 9313 T268 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 9313 T268 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 9314 T268 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362410900704
[junit4:junit4]   2> 9314 T268 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362410900704\solr.xml
[junit4:junit4]   2> 9315 T268 oasc.CoreContainer.<init> New CoreContainer 1063189925
[junit4:junit4]   2> 9315 T268 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362410900704\'
[junit4:junit4]   2> 9315 T268 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362410900704\'
[junit4:junit4]   2> 9372 T268 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 9373 T268 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 9373 T268 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 9373 T268 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 9374 T268 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 9374 T268 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 9375 T268 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 9375 T268 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 9375 T268 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 9376 T268 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 9392 T268 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 9415 T268 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:54603/solr
[junit4:junit4]   2> 9415 T268 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 9416 T268 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54603 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@60201ac
[junit4:junit4]   2> 9417 T268 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 9418 T323 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54603. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 9419 T323 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54603, initiating session
[junit4:junit4]   2> 9419 T270 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54636
[junit4:junit4]   2> 9420 T270 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54636
[junit4:junit4]   2> 9434 T272 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d36046a210007 with negotiated timeout 20000 for client /127.0.0.1:54636
[junit4:junit4]   2> 9434 T323 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54603, sessionid = 0x13d36046a210007, negotiated timeout = 20000
[junit4:junit4]   2> 9435 T324 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@60201ac name:ZooKeeperConnection Watcher:127.0.0.1:54603 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 9435 T268 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 9438 T273 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d36046a210007
[junit4:junit4]   2> 9441 T270 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:54636 which had sessionid 0x13d36046a210007
[junit4:junit4]   2> 9442 T268 oaz.ZooKeeper.close Session: 0x13d36046a210007 closed
[junit4:junit4]   2> 9442 T268 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 9448 T268 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54603/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@69f8c9e8
[junit4:junit4]   2> 9450 T324 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 9457 T268 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 9458 T325 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54603. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 9459 T325 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54603, initiating session
[junit4:junit4]   2> 9459 T270 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54639
[junit4:junit4]   2> 9460 T270 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54639
[junit4:junit4]   2> 9463 T272 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d36046a210008 with negotiated timeout 20000 for client /127.0.0.1:54639
[junit4:junit4]   2> 9464 T325 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54603, sessionid = 0x13d36046a210008, negotiated timeout = 20000
[junit4:junit4]   2> 9464 T326 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@69f8c9e8 name:ZooKeeperConnection Watcher:127.0.0.1:54603/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 9464 T268 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 9466 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210008 type:create cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 9470 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210008 type:create cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 9475 T268 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 10532 T291 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10533 T291 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"2",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54622_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54622"}
[junit4:junit4]   2> 10547 T297 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> 10547 T290 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> 10548 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> 10547 T310 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> 10579 T268 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54631_
[junit4:junit4]   2> 10581 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210008 type:delete cxid:0xb zxid:0x73 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:54631_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:54631_
[junit4:junit4]   2> 10582 T268 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54631_
[junit4:junit4]   2> 10588 T290 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> 10589 T310 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 10589 T310 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> 10590 T326 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 10590 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> 10591 T297 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 10591 T297 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> 10594 T290 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 10605 T327 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362410900704\collection1
[junit4:junit4]   2> 10605 T327 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 10606 T327 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 10606 T327 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 10610 T327 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362410900704\collection1\'
[junit4:junit4]   2> 10612 T327 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362410900704/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 10613 T327 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362410900704/collection1/lib/README' to classloader
[junit4:junit4]   2> 10670 T327 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 10761 T327 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 10762 T327 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 10768 T327 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 11560 T327 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 11572 T327 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 11576 T327 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 11604 T327 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 11611 T327 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 11617 T327 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 11619 T327 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 11620 T327 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 11620 T327 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 11622 T327 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 11622 T327 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 11622 T327 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362410900704\collection1\, dataDir=.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797/jetty2\
[junit4:junit4]   2> 11623 T327 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b4fb007
[junit4:junit4]   2> 11623 T327 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 11624 T327 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty2 forceNew:false
[junit4:junit4]   2> 11624 T327 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty2
[junit4:junit4]   2> 11624 T327 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797/jetty2\index/
[junit4:junit4]   2> 11626 T327 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 11626 T327 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty2\index forceNew:false
[junit4:junit4]   2> 11631 T327 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@44866277 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d4f2490),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 11631 T327 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 11633 T327 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty2\index
[junit4:junit4]   2> 11636 T327 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 11636 T327 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 11637 T327 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 11638 T327 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 11638 T327 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 11638 T327 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 11640 T327 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 11641 T327 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 11641 T327 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 11651 T327 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 11658 T327 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty2
[junit4:junit4]   2> 11658 T327 oass.SolrIndexSearcher.<init> Opening Searcher@3ce62202 main
[junit4:junit4]   2> 11659 T327 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty2\tlog
[junit4:junit4]   2> 11661 T327 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 11661 T327 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 11667 T328 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3ce62202 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 11670 T327 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 11670 T327 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 12211 T291 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12212 T291 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"3",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54631_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54631"}
[junit4:junit4]   2> 12212 T291 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 12213 T291 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4]   2> 12225 T310 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> 12225 T297 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> 12225 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> 12225 T290 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> 12777 T327 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 12777 T327 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54631 collection:collection1 shard:shard2
[junit4:junit4]   2> 12779 T327 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 12797 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210008 type:delete cxid:0x47 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> 12800 T327 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 12801 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210008 type:create cxid:0x48 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12806 T327 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 12806 T327 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 12806 T327 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54631/collection1/
[junit4:junit4]   2> 12806 T327 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 12807 T327 oasc.SyncStrategy.syncToMe http://127.0.0.1:54631/collection1/ has no replicas
[junit4:junit4]   2> 12807 T327 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54631/collection1/
[junit4:junit4]   2> 12807 T327 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 12816 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210008 type:create cxid:0x51 zxid:0x82 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 13889 T291 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13975 T310 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> 13975 T290 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> 13975 T297 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> 13976 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> 13994 T327 oasc.ZkController.register We are http://127.0.0.1:54631/collection1/ and leader is http://127.0.0.1:54631/collection1/
[junit4:junit4]   2> 13994 T327 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54631
[junit4:junit4]   2> 13994 T327 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 13994 T327 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 13994 T327 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 14020 T327 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14040 T268 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 14040 T268 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 14041 T268 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 14424 T268 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 14428 T268 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54640
[junit4:junit4]   2> 14429 T268 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 14430 T268 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 14430 T268 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362410905841
[junit4:junit4]   2> 14431 T268 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362410905841\solr.xml
[junit4:junit4]   2> 14431 T268 oasc.CoreContainer.<init> New CoreContainer 1810231134
[junit4:junit4]   2> 14432 T268 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362410905841\'
[junit4:junit4]   2> 14432 T268 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362410905841\'
[junit4:junit4]   2> 14489 T268 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 14490 T268 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 14490 T268 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 14492 T268 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 14492 T268 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 14493 T268 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 14493 T268 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 14493 T268 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 14494 T268 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 14494 T268 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 14512 T268 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 14534 T268 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:54603/solr
[junit4:junit4]   2> 14534 T268 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 14536 T268 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54603 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@7baa2bac
[junit4:junit4]   2> 14540 T268 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 14541 T339 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54603. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 14542 T339 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54603, initiating session
[junit4:junit4]   2> 14542 T270 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54645
[junit4:junit4]   2> 14543 T270 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54645
[junit4:junit4]   2> 14555 T272 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d36046a210009 with negotiated timeout 20000 for client /127.0.0.1:54645
[junit4:junit4]   2> 14555 T339 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54603, sessionid = 0x13d36046a210009, negotiated timeout = 20000
[junit4:junit4]   2> 14556 T340 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7baa2bac name:ZooKeeperConnection Watcher:127.0.0.1:54603 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 14557 T268 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 14559 T273 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d36046a210009
[junit4:junit4]   2> 14561 T268 oaz.ZooKeeper.close Session: 0x13d36046a210009 closed
[junit4:junit4]   2> 14561 T340 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 14562 T270 oazs.NIOServerCnxn.doIO WARNING caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13d36046a210009, likely client has closed socket
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4]   2> 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 
[junit4:junit4]   2> 14562 T268 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 14563 T270 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:54645 which had sessionid 0x13d36046a210009
[junit4:junit4]   2> 14571 T268 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54603/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@203778a4
[junit4:junit4]   2> 14572 T268 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 14573 T341 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54603. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 14575 T341 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54603, initiating session
[junit4:junit4]   2> 14575 T270 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54648
[junit4:junit4]   2> 14575 T270 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54648
[junit4:junit4]   2> 14579 T272 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d36046a21000a with negotiated timeout 20000 for client /127.0.0.1:54648
[junit4:junit4]   2> 14579 T341 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54603, sessionid = 0x13d36046a21000a, negotiated timeout = 20000
[junit4:junit4]   2> 14580 T342 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@203778a4 name:ZooKeeperConnection Watcher:127.0.0.1:54603/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 14580 T268 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 14581 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a21000a type:create cxid:0x1 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 14584 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a21000a type:create cxid:0x2 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 14588 T268 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 15695 T268 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54640_
[junit4:junit4]   2> 15696 T291 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15696 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a21000a type:delete cxid:0x9 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:54640_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:54640_
[junit4:junit4]   2> 15703 T268 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54640_
[junit4:junit4]   2> 15704 T291 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"3",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54631_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54631"}
[junit4:junit4]   2> 15711 T290 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> 15713 T297 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 15714 T297 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> 15714 T310 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 15715 T310 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> 15717 T342 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 15717 T326 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 15717 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> 15723 T297 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> 15724 T342 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> 15725 T310 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> 15725 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> 15750 T343 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362410905841\collection1
[junit4:junit4]   2> 15750 T343 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 15753 T343 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 15753 T343 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 15758 T343 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362410905841\collection1\'
[junit4:junit4]   2> 15760 T343 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362410905841/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 15760 T343 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362410905841/collection1/lib/README' to classloader
[junit4:junit4]   2> 15783 T290 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 15783 T290 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> 15850 T343 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 15948 T343 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 15951 T343 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 15957 T343 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 16745 T343 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 16757 T343 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 16765 T343 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 16799 T343 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 16805 T343 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 16812 T343 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 16814 T343 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 16815 T343 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 16815 T343 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 16817 T343 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 16817 T343 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 16817 T343 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362410905841\collection1\, dataDir=.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797/jetty3\
[junit4:junit4]   2> 16818 T343 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b4fb007
[junit4:junit4]   2> 16818 T343 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 16819 T343 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3 forceNew:false
[junit4:junit4]   2> 16820 T343 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3
[junit4:junit4]   2> 16820 T343 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797/jetty3\index/
[junit4:junit4]   2> 16821 T343 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 16821 T343 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3\index forceNew:false
[junit4:junit4]   2> 16826 T343 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@159149a lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c70ad1a),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 16826 T343 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 16828 T343 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3\index
[junit4:junit4]   2> 16831 T343 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 16831 T343 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 16832 T343 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 16832 T343 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 16833 T343 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 16833 T343 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 16834 T343 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 16834 T343 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 16835 T343 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 16846 T343 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 16854 T343 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3
[junit4:junit4]   2> 16854 T343 oass.SolrIndexSearcher.<init> Opening Searcher@2987d89b main
[junit4:junit4]   2> 16855 T343 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3\tlog
[junit4:junit4]   2> 16856 T343 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 16857 T343 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 16863 T344 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2987d89b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 16867 T343 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 16867 T343 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 17400 T291 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 17403 T291 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"4",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54640_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54640"}
[junit4:junit4]   2> 17403 T291 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 17403 T291 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 17415 T297 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> 17418 T310 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> 17419 T290 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> 17419 T342 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> 17420 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> 17972 T343 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 17972 T343 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54640 collection:collection1 shard:shard1
[junit4:junit4]   2> 17979 T343 oasc.ZkController.register We are http://127.0.0.1:54640/collection1/ and leader is http://127.0.0.1:54622/collection1/
[junit4:junit4]   2> 17979 T343 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54640
[junit4:junit4]   2> 17979 T343 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 17981 T343 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C19 name=collection1 org.apache.solr.core.SolrCore@6970e732 url=http://127.0.0.1:54640/collection1 node=127.0.0.1:54640_ C19_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:54640_, base_url=http://127.0.0.1:54640}
[junit4:junit4]   2> 17986 T345 C19 P54640 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 17987 T345 C19 P54640 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 17988 T345 C19 P54640 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 17988 T343 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 17988 T345 C19 P54640 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 17991 T345 C19 P54640 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 17992 T268 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 17992 T268 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 17993 T268 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 18004 T268 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18006 T268 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 18017 T306 oasc.CoreContainer.create Creating SolrCore 'onenodecollectioncore' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362410895980\onenodecollectioncore
[junit4:junit4]   2> 18018 T306 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4]   2> 18019 T306 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4]   2> 18019 T306 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4]   2> 18021 T306 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4]   2> 18021 T306 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4]   2> 18028 T306 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4]   2> 18030 T306 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362410895980\onenodecollectioncore\'
[junit4:junit4]   2> 18103 T306 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 18193 T306 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 18195 T306 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 18202 T306 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 18957 T306 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 18973 T306 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 18977 T306 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 19004 T306 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 19010 T306 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 19016 T306 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 19018 T306 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 19019 T306 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 19019 T306 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 19021 T306 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 19021 T306 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 19021 T306 oasc.SolrCore.<init> [onenodecollectioncore] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362410895980\onenodecollectioncore\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-BasicDistributedZk2Test-1362410891798\onenodecollection\
[junit4:junit4]   2> 19023 T306 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b4fb007
[junit4:junit4]   2> 19024 T306 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 19025 T306 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-BasicDistributedZk2Test-1362410891798\onenodecollection forceNew:false
[junit4:junit4]   2> 19025 T306 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-BasicDistributedZk2Test-1362410891798\onenodecollection
[junit4:junit4]   2> 19025 T306 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-BasicDistributedZk2Test-1362410891798\onenodecollection\index/
[junit4:junit4]   2> 19027 T306 oasc.SolrCore.initIndex WARNING [onenodecollectioncore] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-BasicDistributedZk2Test-1362410891798\onenodecollection\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 19027 T306 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-BasicDistributedZk2Test-1362410891798\onenodecollection\index forceNew:false
[junit4:junit4]   2> 19031 T306 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b7b908a lockFactory=org.apache.lucene.store.NativeFSLockFactory@42f0ffda),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 19031 T306 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 19033 T306 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-BasicDistributedZk2Test-1362410891798\onenodecollection\index
[junit4:junit4]   2> 19038 T306 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 19038 T306 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 19039 T306 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 19039 T306 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 19040 T306 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 19040 T306 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 19040 T306 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 19041 T306 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 19041 T306 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 19056 T306 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 19064 T306 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-BasicDistributedZk2Test-1362410891798\onenodecollection
[junit4:junit4]   2> 19065 T306 oass.SolrIndexSearcher.<init> Opening Searcher@191c0328 main
[junit4:junit4]   2> 19065 T306 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-BasicDistributedZk2Test-1362410891798\onenodecollection\tlog
[junit4:junit4]   2> 19067 T291 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19068 T291 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"4",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54640_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54640"}
[junit4:junit4]   2> 19068 T306 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 19069 T306 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 19072 T306 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-BasicDistributedZk2Test-1362410891798\onenodecollection
[junit4:junit4]   2> 19072 T347 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@191c0328 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 19074 T306 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4]   2> 19095 T291 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":"none",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"onenodecollectioncore",
[junit4:junit4]   2> 	  "collection":"onenodecollection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54622_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54622"}
[junit4:junit4]   2> 19095 T291 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4]   2> 19095 T291 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 19107 T297 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> 19107 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> 19107 T342 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> 19107 T310 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> 19107 T290 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> 20079 T306 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4]   2> 20080 T306 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:54622 collection:onenodecollection shard:shard1
[junit4:junit4]   2> 20081 T306 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4]   2> 20100 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210006 type:delete cxid:0xa1 zxid:0xac txntype:-1 reqpath:n/a Error Path:/solr/collections/onenodecollection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/onenodecollection/leaders
[junit4:junit4]   2> 20103 T306 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 20104 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210006 type:create cxid:0xa2 zxid:0xad txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 20109 T306 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 20110 T306 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 20110 T306 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54622/onenodecollectioncore/
[junit4:junit4]   2> 20111 T306 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 20111 T306 oasc.SyncStrategy.syncToMe http://127.0.0.1:54622/onenodecollectioncore/ has no replicas
[junit4:junit4]   2> 20112 T306 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54622/onenodecollectioncore/
[junit4:junit4]   2> 20112 T306 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4]   2> 20123 T273 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d36046a210006 type:create cxid:0xac zxid:0xb1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 20668 T291 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20687 T297 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> 20688 T310 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> 20688 T290 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> 20689 T342 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> 20689 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> 20732 T306 oasc.ZkController.register We are http://127.0.0.1:54622/onenodecollectioncore/ and leader is http://127.0.0.1:54622/onenodecollectioncore/
[junit4:junit4]   2> 20732 T306 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:54622
[junit4:junit4]   2> 20733 T306 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 20733 T306 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4]   2> 20738 T306 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20740 T268 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4]   2> 20741 T268 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 21735 T268 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C19_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:54640_, base_url=http://127.0.0.1:54640}
[junit4:junit4]   2> 22064 T345 C19 P54640 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:54622/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 22072 T345 C19 P54640 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4]   2> 22087 T345 C19 P54640 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:54640 START replicas=[http://127.0.0.1:54622/collection1/] nUpdates=100
[junit4:junit4]   2> 22088 T345 C19 P54640 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 22088 T345 C19 P54640 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 22088 T345 C19 P54640 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 22089 T345 C19 P54640 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 22089 T345 C19 P54640 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 22089 T345 C19 P54640 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:54622/collection1/. core=collection1
[junit4:junit4]   2> 22089 T345 C19 P54640 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C20 name=collection1 org.apache.solr.core.SolrCore@7cc3f611 url=http://127.0.0.1:54622/collection1 node=127.0.0.1:54622_ C20_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:54622_, base_url=http://127.0.0.1:54622, leader=true}
[junit4:junit4]   2> 22104 T305 C20 P54622 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1 
[junit4:junit4]   2> 22120 T303 C20 P54622 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 22121 T303 C20 P54622 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty1
[junit4:junit4]   2> 22124 T303 C20 P54622 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5022ac3e lockFactory=org.apache.lucene.store.NativeFSLockFactory@3208a6c4),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 22125 T303 C20 P54622 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 22125 T303 C20 P54622 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5022ac3e lockFactory=org.apache.lucene.store.NativeFSLockFactory@3208a6c4),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5022ac3e lockFactory=org.apache.lucene.store.NativeFSLockFactory@3208a6c4),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 22125 T303 C20 P54622 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 22126 T303 C20 P54622 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty1
[junit4:junit4]   2> 22126 T303 C20 P54622 oass.SolrIndexSearcher.<init> Opening Searcher@370b5789 realtime
[junit4:junit4]   2> 22127 T303 C20 P54622 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 22127 T303 C20 P54622 /update {waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 24
[junit4:junit4]   2> 22185 T345 C19 P54640 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 22185 T345 C19 P54640 oascsi.HttpClientUtil.createClient Creating new http client, config:connTimeout=5000&socketTimeout=20000&allowCompression=false&maxConnections=10000&maxConnectionsPerHost=10000
[junit4:junit4]   2> 22188 T291 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22189 T291 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":"none",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"onenodecollectioncore",
[junit4:junit4]   2> 	  "collection":"onenodecollection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54622_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54622"}
[junit4:junit4]   2> 22195 T345 C19 P54640 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 22199 T306 C20 P54622 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 22199 T306 C20 P54622 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 22201 T345 C19 P54640 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 22201 T345 C19 P54640 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 22201 T345 C19 P54640 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 22204 T301 C20 P54622 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty1
[junit4:junit4]   2> 22205 T301 C20 P54622 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty1\index
[junit4:junit4]   2> 22205 T301 C20 P54622 REQ /replication {command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1 
[junit4:junit4]   2> 22206 T345 C19 P54640 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 22209 T345 C19 P54640 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3\index.20130304152833996 forceNew:false
[junit4:junit4]   2> 22209 T345 C19 P54640 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3
[junit4:junit4]   2> 22210 T310 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> 22210 T290 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> 22211 T342 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> 22211 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> 22212 T297 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> 22212 T345 C19 P54640 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@6a300285 lockFactory=org.apache.lucene.store.NativeFSLockFactory@50ea3aaf)) fullCopy=false
[junit4:junit4]   2> 22227 T302 C20 P54622 REQ /replication {file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=4 
[junit4:junit4]   2> 22240 T345 C19 P54640 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3\index
[junit4:junit4]   2> 22241 T345 C19 P54640 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 22241 T345 C19 P54640 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3
[junit4:junit4]   2> 22246 T345 C19 P54640 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3
[junit4:junit4]   2> 22246 T345 C19 P54640 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 22246 T345 C19 P54640 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 22246 T345 C19 P54640 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3
[junit4:junit4]   2> 22250 T345 C19 P54640 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@159149a lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c70ad1a),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@159149a lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c70ad1a),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 22251 T345 C19 P54640 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 22251 T345 C19 P54640 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 22251 T345 C19 P54640 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3
[junit4:junit4]   2> 22251 T345 C19 P54640 oass.SolrIndexSearcher.<init> Opening Searcher@6db0b74d main
[junit4:junit4]   2> 22253 T344 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6db0b74d main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 22254 T344 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3\index
[junit4:junit4]   2> 22254 T345 C19 P54640 oash.SnapPuller.fetchLatestIndex removing temporary index download directory files MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@6a300285 lockFactory=org.apache.lucene.store.NativeFSLockFactory@50ea3aaf))
[junit4:junit4]   2> 22254 T345 C19 P54640 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3\index.20130304152833996
[junit4:junit4]   2> 22254 T345 C19 P54640 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3\index
[junit4:junit4]   2> 22255 T345 C19 P54640 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 22255 T345 C19 P54640 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 22255 T345 C19 P54640 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 22255 T345 C19 P54640 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 22258 T345 C19 P54640 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 22728 T268 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22729 T268 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4]   2> 22730 T268 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C21 name=onenodecollectioncore org.apache.solr.core.SolrCore@3ccbada1 url=http://127.0.0.1:54622/onenodecollectioncore node=127.0.0.1:54622_ C21_STATE=coll:onenodecollection core:onenodecollectioncore props:{shard=shard1, roles=none, state=active, core=onenodecollectioncore, collection=onenodecollection, node_name=127.0.0.1:54622_, base_url=http://127.0.0.1:54622, leader=true}
[junit4:junit4]   2> 22758 T304 C21 P54622 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-BasicDistributedZk2Test-1362410891798\onenodecollection
[junit4:junit4]   2> 22762 T304 C21 P54622 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b7b908a lockFactory=org.apache.lucene.store.NativeFSLockFactory@42f0ffda),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 22763 T304 C21 P54622 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 22789 T304 C21 P54622 /update {wt=javabin&version=2} {add=[1 (1428591387133083648)]} 0 36
[junit4:junit4]   2> 22799 T306 C21 P54622 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 22801 T306 C21 P54622 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b7b908a lockFactory=org.apache.lucene.store.NativeFSLockFactory@42f0ffda),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b7b908a lockFactory=org.apache.lucene.store.NativeFSLockFactory@42f0ffda),segFN=segments_2,generation=2,filenames=[_0.fnm, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0_nrm.cfe, segments_2, _0.fdx, _0_dv.cfs, _0_nrm.cfs, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, _0_dv.cfe]
[junit4:junit4]   2> 22801 T306 C21 P54622 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_0.fnm, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0_nrm.cfe, segments_2, _0.fdx, _0_dv.cfs, _0_nrm.cfs, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, _0_dv.cfe]
[junit4:junit4]   2> 22803 T306 C21 P54622 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-BasicDistributedZk2Test-1362410891798\onenodecollection
[junit4:junit4]   2> 22804 T306 C21 P54622 oass.SolrIndexSearcher.<init> Opening Searcher@38e98def main
[junit4:junit4]   2> 22807 T306 C21 P54622 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 22808 T347 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@38e98def main{StandardDirectoryReader(segments_2:3 _0(5.0):C1)}
[junit4:junit4]   2> 22808 T347 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-BasicDistributedZk2Test-1362410891798\onenodecollection\index
[junit4:junit4]   2> 22809 T306 C21 P54622 /update {waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 10
[junit4:junit4]   2> 22814 T301 C21 P54622 REQ /select {q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 22816 T268 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 22827 T302 C21 P54622 REQ /select {q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> ASYNC  NEW_CORE C22 name=collection1 org.apache.solr.core.SolrCore@3ccbd0e0 url=http://127.0.0.1:54610/collection1 node=127.0.0.1:54610_ C22_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:54610_, base_url=http://127.0.0.1:54610, leader=true}
[junit4:junit4]   2> 22836 T281 C22 P54610 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\control\data
[junit4:junit4]   2> 22843 T281 C22 P54610 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2d1415e6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3110ae99),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 22844 T281 C22 P54610 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 22850 T281 C22 P54610 /update {wt=javabin&version=2} {add=[1 (1428591387214872576)]} 0 14
[junit4:junit4]   2> 22903 T336 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1428591387246329856)]} 0 4
[junit4:junit4]   2> 22904 T305 C20 P54622 /update {wt=javabin&version=2} {add=[1 (1428591387246329856)]} 0 45
[junit4:junit4]   2> 22910 T282 C22 P54610 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 22915 T282 C22 P54610 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2d1415e6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3110ae99),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2d1415e6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3110ae99),segFN=segments_2,generation=2,filenames=[_0.fnm, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0_nrm.cfe, segments_2, _0.fdx, _0_dv.cfs, _0_nrm.cfs, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, _0_dv.cfe]
[junit4:junit4]   2> 22915 T282 C22 P54610 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_0.fnm, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0_nrm.cfe, segments_2, _0.fdx, _0_dv.cfs, _0_nrm.cfs, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, _0_dv.cfe]
[junit4:junit4]   2> 22920 T282 C22 P54610 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\control\data
[junit4:junit4]   2> 22925 T282 C22 P54610 oass.SolrIndexSearcher.<init> Opening Searcher@3e8ee16c main
[junit4:junit4]   2> 22927 T294 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3e8ee16c main{StandardDirectoryReader(segments_2:3 _0(5.0):C1)}
[junit4:junit4]   2> 22928 T294 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\control\data\index
[junit4:junit4]   2> 22929 T282 C22 P54610 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 22929 T282 C22 P54610 /update {waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 19
[junit4:junit4]   2> 22933 T303 C20 P54622 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 22938 T303 C20 P54622 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5022ac3e lockFactory=org.apache.lucene.store.NativeFSLockFactory@3208a6c4),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5022ac3e lockFactory=org.apache.lucene.store.NativeFSLockFactory@3208a6c4),segFN=segments_3,generation=3,filenames=[_0.fnm, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0_nrm.cfe, _0.fdx, _0_dv.cfs, _0_nrm.cfs, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, segments_3, _0_dv.cfe]
[junit4:junit4]   2> 22939 T303 C20 P54622 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0.fnm, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0_nrm.cfe, _0.fdx, _0_dv.cfs, _0_nrm.cfs, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, segments_3, _0_dv.cfe]
[junit4:junit4]   2> 22939 T303 C20 P54622 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty1
[junit4:junit4]   2> 22941 T303 C20 P54622 oass.SolrIndexSearcher.<init> Opening Searcher@5ba222 main
[junit4:junit4]   2> 22942 T303 C20 P54622 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty1\index
[junit4:junit4]   2> 22943 T303 C20 P54622 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 22944 T312 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5ba222 main{StandardDirectoryReader(segments_3:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 22944 T312 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty1\index
[junit4:junit4]   2> 22944 T303 C20 P54622 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:54640/collection1/, StdNode: http://127.0.0.1:54631/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4]   2> 22953 T338 C19 P54640 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> ASYNC  NEW_CORE C23 name=collection1 org.apache.solr.core.SolrCore@27f143e9 url=http://127.0.0.1:54631/collection1 node=127.0.0.1:54631_ C23_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:54631_, base_url=http://127.0.0.1:54631, leader=true}
[junit4:junit4]   2> 22955 T318 C23 P54631 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 22956 T318 C23 P54631 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty2
[junit4:junit4]   2> 22963 T318 C23 P54631 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@44866277 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d4f2490),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 22965 T338 C19 P54640 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@159149a lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c70ad1a),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@159149a lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c70ad1a),segFN=segments_3,generation=3,filenames=[_0.fnm, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0_nrm.cfe, _0.fdx, _0_dv.cfs, _0_nrm.cfs, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, segments_3, _0_dv.cfe]
[junit4:junit4]   2> 22966 T338 C19 P54640 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0.fnm, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0_nrm.cfe, _0.fdx, _0_dv.cfs, _0_nrm.cfs, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, segments_3, _0_dv.cfe]
[junit4:junit4]   2> 22966 T318 C23 P54631 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 22967 T338 C19 P54640 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3
[junit4:junit4]   2> 22968 T318 C23 P54631 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@44866277 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d4f2490),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@44866277 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d4f2490),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 22969 T318 C23 P54631 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 22970 T318 C23 P54631 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty2
[junit4:junit4]   2> 22971 T318 C23 P54631 oass.SolrIndexSearcher.<init> Opening Searcher@76a67dab main
[junit4:junit4]   2> 22972 T328 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@76a67dab main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 22973 T318 C23 P54631 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 22973 T328 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty2\index
[junit4:junit4]   2> 22973 T318 C23 P54631 /update {waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 18
[junit4:junit4]   2> 22974 T338 C19 P54640 oass.SolrIndexSearcher.<init> Opening Searcher@2a8f9112 main
[junit4:junit4]   2> 22975 T344 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2a8f9112 main{StandardDirectoryReader(segments_3:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 22976 T344 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3\index
[junit4:junit4]   2> 22978 T338 C19 P54640 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 22978 T338 C19 P54640 /update {waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 25
[junit4:junit4]   2> 22979 T303 C20 P54622 /update {waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 46
[junit4:junit4]   2> 22980 T268 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):230
[junit4:junit4]   2> 22981 T268 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 23708 T291 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 23709 T291 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"4",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54640_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54640"}
[junit4:junit4]   2> 23722 T310 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> 23722 T297 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> 23722 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> 23722 T342 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> 23722 T290 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> 23974 T268 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 23976 T268 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4]   2> 23979 T284 C22 P54610 REQ /select {q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 23980 T268 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54603/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@60ba562f
[junit4:junit4]   2> 23982 T268 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 23982 T353 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54603. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 23983 T353 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54603, initiating session
[junit4:junit4]   2> 23983 T270 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54663
[junit4:junit4]   2> 23983 T270 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54663
[junit4:junit4]   2> 23986 T272 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d36046a21000b with negotiated timeout 10000 for client /127.0.0.1:54663
[junit4:junit4]   2> 23986 T353 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54603, sessionid = 0x13d36046a21000b, negotiated timeout = 10000
[junit4:junit4]   2> 23987 T354 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@60ba562f name:ZooKeeperConnection Watcher:127.0.0.1:54603/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 23987 T268 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 23989 T268 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 23993 T273 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d36046a21000b
[junit4:junit4]   2> 23994 T270 oazs.NIOServerCnxn.doIO WARNING caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13d36046a21000b, likely client has closed socket
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4]   2> 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 
[junit4:junit4]   2> 23994 T268 oaz.ZooKeeper.close Session: 0x13d36046a21000b closed
[junit4:junit4]   2> 23994 T354 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 23995 T270 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:54663 which had sessionid 0x13d36046a21000b
[junit4:junit4]   2> 23998 T301 C20 P54622 REQ /select {q=*:*&distrib=false&wt=javabin&version=2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 24001 T321 C23 P54631 REQ /select {q=*:*&distrib=false&wt=javabin&version=2} hits=0 status=0 QTime=1 
[junit4:junit4]   2>  C19_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:54640_, base_url=http://127.0.0.1:54640}
[junit4:junit4]   2> 24008 T334 C19 P54640 REQ /select {NOW=1362410915793&shard.url=127.0.0.1:54622/collection1/|127.0.0.1:54640/collection1/&fl=id,score&start=0&q=*:*&distrib=false&wt=javabin&isShard=true&fsv=true&version=2&rows=10} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 24008 T317 C23 P54631 REQ /select {NOW=1362410915793&shard.url=127.0.0.1:54631/collection1/&fl=id,score&start=0&q=*:*&distrib=false&wt=javabin&isShard=true&fsv=true&version=2&rows=10} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 24022 T337 C19 P54640 REQ /select {NOW=1362410915793&shard.url=127.0.0.1:54622/collection1/|127.0.0.1:54640/collection1/&ids=1&q=*:*&distrib=false&wt=javabin&isShard=true&version=2} status=0 QTime=1 
[junit4:junit4]   2> 24023 T322 C23 P54631 REQ /select {q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=20 
[junit4:junit4]   2> 24032 T286 C22 P54610 /update {wt=javabin&version=2} {add=[2 (1428591388464775168)]} 0 4
[junit4:junit4]   2> 24038 T318 C23 P54631 /update {wt=javabin&version=2} {add=[2 (1428591388472115200)]} 0 3
[junit4:junit4]   2> 24043 T281 C22 P54610 /update {wt=javabin&version=2} {add=[3 (1428591388478406656)]} 0 2
[junit4:junit4]   2> 24055 T319 C23 P54631 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[3 (1428591388490989568)]} 0 2
[junit4:junit4]   2> 24056 T302 C20 P54622 /update {wt=javabin&version=2} {add=[3]} 0 10
[junit4:junit4]   2> 24060 T282 C22 P54610 /update {wt=javabin&version=2} {add=[4 (1428591388497281024)]} 0 1
[junit4:junit4]   2> 24073 T336 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[4 (1428591388502523904)]} 0 3
[junit4:junit4]   2> 24073 T305 C20 P54622 /update {wt=javabin&version=2} {add=[4 (1428591388502523904)]} 0 9
[junit4:junit4]   2> 24078 T283 C22 P54610 /update {wt=javabin&version=2} {add=[5 (1428591388515106816)]} 0 2
[junit4:junit4]   2> 24082 T320 C23 P54631 /update {wt=javabin&version=2} {add=[5 (1428591388519301120)]} 0 2
[junit4:junit4]   2> 24086 T285 C22 P54610 /update {wt=javabin&version=2} {add=[6 (1428591388524544000)]} 0 2
[junit4:junit4]   2> 24092 T321 C23 P54631 /update {wt=javabin&version=2} {add=[6 (1428591388528738304)]} 0 3
[junit4:junit4]   2> 24098 T284 C22 P54610 /update {wt=javabin&version=2} {add=[7 (1428591388536078336)]} 0 2
[junit4:junit4]   2> 24109 T317 C23 P54631 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[7 (1428591388547612672)]} 0 2
[junit4:junit4]   2> 24110 T303 C20 P54622 /update {wt=javabin&version=2} {add=[7]} 0 7
[junit4:junit4]   2> 24116 T286 C22 P54610 /update {wt=javabin&version=2} {add=[8 (1428591388554952704)]} 0 2
[junit4:junit4]   2> 24132 T338 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[8 (1428591388564389888)]} 0 4
[junit4:junit4]   2> 24133 T304 C20 P54622 /update {wt=javabin&version=2} {add=[8 (1428591388564389888)]} 0 10
[junit4:junit4]   2> 24138 T281 C22 P54610 /update {wt=javabin&version=2} {add=[9 (1428591388580118528)]} 0 1
[junit4:junit4]   2> 24143 T322 C23 P54631 /update {wt=javabin&version=2} {add=[9 (1428591388583264256)]} 0 2
[junit4:junit4]   2> 24146 T282 C22 P54610 /update {wt=javabin&version=2} {add=[10 (1428591388587458560)]} 0 1
[junit4:junit4]   2> 24161 T333 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10 (1428591388595847168)]} 0 1
[junit4:junit4]   2> 24162 T306 C20 P54622 /update {distrib.from=http://127.0.0.1:54631/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[10 (1428591388595847168)]} 0 10
[junit4:junit4]   2> 24163 T318 C23 P54631 /update {wt=javabin&version=2} {add=[10]} 0 14
[junit4:junit4]   2> 24166 T283 C22 P54610 /update {wt=javabin&version=2} {add=[11 (1428591388608430080)]} 0 1
[junit4:junit4]   2> 24181 T335 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[11 (1428591388616818688)]} 0 1
[junit4:junit4]   2> 24182 T301 C20 P54622 /update {distrib.from=http://127.0.0.1:54631/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[11 (1428591388616818688)]} 0 9
[junit4:junit4]   2> 24183 T319 C23 P54631 /update {wt=javabin&version=2} {add=[11]} 0 15
[junit4:junit4]   2> 24187 T285 C22 P54610 /update {wt=javabin&version=2} {add=[12 (1428591388629401600)]} 0 2
[junit4:junit4]   2> 24203 T334 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[12 (1428591388641984512)]} 0 2
[junit4:junit4]   2> 24204 T302 C20 P54622 /update {distrib.from=http://127.0.0.1:54631/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[12 (1428591388641984512)]} 0 8
[junit4:junit4]   2> 24204 T320 C23 P54631 /update {wt=javabin&version=2} {add=[12]} 0 12
[junit4:junit4]   2> 24208 T284 C22 P54610 /update {wt=javabin&version=2} {add=[13 (1428591388652470272)]} 0 1
[junit4:junit4]   2> 24217 T337 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[13 (1428591388656664576)]} 0 2
[junit4:junit4]   2> 24218 T305 C20 P54622 /update {wt=javabin&version=2} {add=[13 (1428591388656664576)]} 0 7
[junit4:junit4]   2> 24222 T286 C22 P54610 /update {wt=javabin&version=2} {add=[14 (1428591388667150336)]} 0 1
[junit4:junit4]   2> 24233 T336 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[14 (1428591388673441792)]} 0 1
[junit4:junit4]   2> 24234 T303 C20 P54622 /update {distrib.from=http://127.0.0.1:54631/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[14 (1428591388673441792)]} 0 7
[junit4:junit4]   2> 24235 T321 C23 P54631 /update {wt=javabin&version=2} {add=[14]} 0 10
[junit4:junit4]   2> 24239 T281 C22 P54610 /update {wt=javabin&version=2} {add=[15 (1428591388684976128)]} 0 1
[junit4:junit4]   2> 24247 T338 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[15 (1428591388689170432)]} 0 2
[junit4:junit4]   2> 24248 T304 C20 P54622 /update {wt=javabin&version=2} {add=[15 (1428591388689170432)]} 0 6
[junit4:junit4]   2> 24252 T282 C22 P54610 /update {wt=javabin&version=2} {add=[16 (1428591388698607616)]} 0 1
[junit4:junit4]   2> 24290 T333 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[16 (1428591388705947648)]} 0 2
[junit4:junit4]   2> 24291 T306 C20 P54622 /update {distrib.from=http://127.0.0.1:54631/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[16 (1428591388705947648)]} 0 34
[junit4:junit4]   2> 24292 T317 C23 P54631 /update {wt=javabin&version=2} {add=[16]} 0 38
[junit4:junit4]   2> 24334 T283 C22 P54610 /update {wt=javabin&version=2} {add=[17 (1428591388783542272)]} 0 39
[junit4:junit4]   2> 24342 T319 C23 P54631 /update {wt=javabin&version=2} {add=[17 (1428591388791930880)]} 0 5
[junit4:junit4]   2> 24348 T285 C22 P54610 /update {wt=javabin&version=2} {add=[100 (1428591388799270912)]} 0 1
[junit4:junit4]   2> 24356 T335 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[100 (1428591388803465216)]} 0 1
[junit4:junit4]   2> 24358 T302 C20 P54622 /update {wt=javabin&version=2} {add=[100 (1428591388803465216)]} 0 7
[junit4:junit4]   2> 24361 T284 C22 P54610 /update {wt=javabin&version=2} {add=[101 (1428591388812902400)]} 0 1
[junit4:junit4]   2> 24368 T334 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[101 (1428591388817096704)]} 0 0
[junit4:junit4]   2> 24370 T305 C20 P54622 /update {wt=javabin&version=2} {add=[101 (1428591388817096704)]} 0 6
[junit4:junit4]   2> 24373 T286 C22 P54610 /update {wt=javabin&version=2} {add=[102 (1428591388825485312)]} 0 1
[junit4:junit4]   2> 24381 T337 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[102 (1428591388829679616)]} 0 1
[junit4:junit4]   2> 24382 T303 C20 P54622 /update {wt=javabin&version=2} {add=[102 (1428591388829679616)]} 0 6
[junit4:junit4]   2> 24386 T281 C22 P54610 /update {wt=javabin&version=2} {add=[103 (1428591388839116800)]} 0 1
[junit4:junit4]   2> 24392 T320 C23 P54631 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[103 (1428591388846456832)]} 0 0
[junit4:junit4]   2> 24394 T304 C20 P54622 /update {wt=javabin&version=2} {add=[103]} 0 5
[junit4:junit4]   2> 24398 T283 C22 P54610 /update {wt=javabin&version=2} {add=[104 (1428591388851699712)]} 0 1
[junit4:junit4]   2> 24403 T321 C23 P54631 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[104 (1428591388856942592)]} 0 1
[junit4:junit4]   2> 24405 T301 C20 P54622 /update {wt=javabin&version=2} {add=[104]} 0 5
[junit4:junit4]   2> 24413 T285 C22 P54610 /update {wt=javabin&version=2} {add=[105 (1428591388867428352)]} 0 1
[junit4:junit4]   2> 24418 T318 C23 P54631 /update {wt=javabin&version=2} {add=[105 (1428591388872671232)]} 0 1
[junit4:junit4]   2> 24423 T284 C22 P54610 /update {wt=javabin&version=2} {add=[106 (1428591388877914112)]} 0 1
[junit4:junit4]   2> 24427 T317 C23 P54631 /update {wt=javabin&version=2} {add=[106 (1428591388882108416)]} 0 1
[junit4:junit4]   2> 24430 T286 C22 P54610 /update {wt=javabin&version=2} {add=[107 (1428591388885254144)]} 0 1
[junit4:junit4]   2> 24440 T336 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[107 (1428591388891545600)]} 0 1
[junit4:junit4]   2> 24441 T302 C20 P54622 /update {distrib.from=http://127.0.0.1:54631/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[107 (1428591388891545600)]} 0 6
[junit4:junit4]   2> 24441 T319 C23 P54631 /update {wt=javabin&version=2} {add=[107]} 0 8
[junit4:junit4]   2> 24445 T282 C22 P54610 /update {wt=javabin&version=2} {add=[108 (1428591388902031360)]} 0 1
[junit4:junit4]   2> 24453 T333 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[108 (1428591388907274240)]} 0 1
[junit4:junit4]   2> 24454 T305 C20 P54622 /update {wt=javabin&version=2} {add=[108 (1428591388907274240)]} 0 6
[junit4:junit4]   2> 24458 T281 C22 P54610 /update {wt=javabin&version=2} {add=[109 (1428591388914614272)]} 0 1
[junit4:junit4]   2> 24464 T335 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[109 (1428591388917760000)]} 0 1
[junit4:junit4]   2> 24465 T303 C20 P54622 /update {wt=javabin&version=2} {add=[109 (1428591388917760000)]} 0 5
[junit4:junit4]   2> 24470 T283 C22 P54610 /update {wt=javabin&version=2} {add=[110 (1428591388927197184)]} 0 1
[junit4:junit4]   2> 24477 T334 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[110 (1428591388932440064)]} 0 0
[junit4:junit4]   2> 24479 T304 C20 P54622 /update {wt=javabin&version=2} {add=[110 (1428591388932440064)]} 0 6
[junit4:junit4]   2> 24484 T285 C22 P54610 /update {wt=javabin&version=2} {add=[111 (1428591388941877248)]} 0 1
[junit4:junit4]   2> 24493 T337 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[111 (1428591388948168704)]} 0 1
[junit4:junit4]   2> 24494 T306 C20 P54622 /update {distrib.from=http://127.0.0.1:54631/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[111 (1428591388948168704)]} 0 5
[junit4:junit4]   2> 24495 T320 C23 P54631 /update {wt=javabin&version=2} {add=[111]} 0 8
[junit4:junit4]   2> 24499 T284 C22 P54610 /update {wt=javabin&version=2} {add=[112 (1428591388957605888)]} 0 1
[junit4:junit4]   2> 24508 T321 C23 P54631 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[112 (1428591388967043072)]} 0 1
[junit4:junit4]   2> 24510 T301 C20 P54622 /update {wt=javabin&version=2} {add=[112]} 0 7
[junit4:junit4]   2> 24514 T286 C22 P54610 /update {wt=javabin&version=2} {add=[113 (1428591388973334528)]} 0 1
[junit4:junit4]   2> 24524 T338 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[113 (1428591388979625984)]} 0 1
[junit4:junit4]   2> 24526 T302 C20 P54622 /update {distrib.from=http://127.0.0.1:54631/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[113 (1428591388979625984)]} 0 7
[junit4:junit4]   2> 24526 T322 C23 P54631 /update {wt=javabin&version=2} {add=[113]} 0 10
[junit4:junit4]   2> 24530 T282 C22 P54610 /update {wt=javabin&version=2} {add=[114 (1428591388990111744)]} 0 1
[junit4:junit4]   2> 24539 T336 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[114 (1428591388996403200)]} 0 1
[junit4:junit4]   2> 24540 T305 C20 P54622 /update {distrib.from=http://127.0.0.1:54631/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[114 (1428591388996403200)]} 0 5
[junit4:junit4]   2> 24541 T318 C23 P54631 /update {wt=javabin&version=2} {add=[114]} 0 8
[junit4:junit4]   2> 24545 T281 C22 P54610 /update {wt=javabin&version=2} {add=[115 (1428591389005840384)]} 0 1
[junit4:junit4]   2> 24549 T317 C23 P54631 /update {wt=javabin&version=2} {add=[115 (1428591389010034688)]} 0 1
[junit4:junit4]   2> 24556 T283 C22 P54610 /update {wt=javabin&version=2} {add=[116 (1428591389017374720)]} 0 4
[junit4:junit4]   2> 24560 T319 C23 P54631 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[116 (1428591389022617600)]} 0 0
[junit4:junit4]   2> 24562 T303 C20 P54622 /update {wt=javabin&version=2} {add=[116]} 0 4
[junit4:junit4]   2> 24566 T285 C22 P54610 /update {wt=javabin&version=2} {add=[117 (1428591389027860480)]} 0 1
[junit4:junit4]   2> 24571 T320 C23 P54631 /update {wt=javabin&version=2} {add=[117 (1428591389033103360)]} 0 1
[junit4:junit4]   2> 24574 T284 C22 P54610 /update {wt=javabin&version=2} {add=[118 (1428591389036249088)]} 0 1
[junit4:junit4]   2> 24581 T333 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[118 (1428591389040443392)]} 0 1
[junit4:junit4]   2> 24582 T304 C20 P54622 /update {distrib.from=http://127.0.0.1:54631/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[118 (1428591389040443392)]} 0 5
[junit4:junit4]   2> 24583 T321 C23 P54631 /update {wt=javabin&version=2} {add=[118]} 0 8
[junit4:junit4]   2> 24588 T286 C22 P54610 /update {wt=javabin&version=2} {add=[119 (1428591389050929152)]} 0 1
[junit4:junit4]   2> 24592 T322 C23 P54631 /update {wt=javabin&version=2} {add=[119 (1428591389056172032)]} 0 1
[junit4:junit4]   2> 24596 T282 C22 P54610 /update {wt=javabin&version=2} {add=[120 (1428591389059317760)]} 0 1
[junit4:junit4]   2> 24600 T318 C23 P54631 /update {wt=javabin&version=2} {add=[120 (1428591389063512064)]} 0 1
[junit4:junit4]   2> 24604 T281 C22 P54610 /update {wt=javabin&version=2} {add=[121 (1428591389068754944)]} 0 1
[junit4:junit4]   2> 24607 T317 C23 P54631 /update {wt=javabin&version=2} {add=[121 (1428591389070852096)]} 0 1
[junit4:junit4]   2> 24611 T283 C22 P54610 /update {wt=javabin&version=2} {add=[122 (1428591389076094976)]} 0 1
[junit4:junit4]   2> 24618 T335 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[122 (1428591389079240704)]} 0 0
[junit4:junit4]   2> 24619 T306 C20 P54622 /update {wt=javabin&version=2} {add=[122 (1428591389079240704)]} 0 5
[junit4:junit4]   2> 24623 T285 C22 P54610 /update {wt=javabin&version=2} {add=[123 (1428591389087629312)]} 0 1
[junit4:junit4]   2> 24631 T334 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[123 (1428591389091823616)]} 0 1
[junit4:junit4]   2> 24632 T301 C20 P54622 /update {wt=javabin&version=2} {add=[123 (1428591389091823616)]} 0 6
[junit4:junit4]   2> 24635 T284 C22 P54610 /update {wt=javabin&version=2} {add=[124 (1428591389100212224)]} 0 1
[junit4:junit4]   2> 24644 T337 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[124 (1428591389106503680)]} 0 1
[junit4:junit4]   2> 24645 T302 C20 P54622 /update {distrib.from=http://127.0.0.1:54631/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[124 (1428591389106503680)]} 0 5
[junit4:junit4]   2> 24646 T319 C23 P54631 /update {wt=javabin&version=2} {add=[124]} 0 8
[junit4:junit4]   2> 24651 T286 C22 P54610 /update {wt=javabin&version=2} {add=[125 (1428591389116989440)]} 0 2
[junit4:junit4]   2> 24656 T338 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[125 (1428591389120135168)]} 0 0
[junit4:junit4]   2> 24658 T305 C20 P54622 /update {wt=javabin&version=2} {add=[125 (1428591389120135168)]} 0 5
[junit4:junit4]   2> 24666 T282 C22 P54610 /update {wt=javabin&version=2} {add=[126 (1428591389132718080)]} 0 1
[junit4:junit4]   2> 24670 T320 C23 P54631 /update {wt=javabin&version=2} {add=[126 (1428591389136912384)]} 0 1
[junit4:junit4]   2> 24674 T281 C22 P54610 /update {wt=javabin&version=2} {add=[127 (1428591389141106688)]} 0 1
[junit4:junit4]   2> 24679 T321 C23 P54631 /update {wt=javabin&version=2} {add=[127 (1428591389145300992)]} 0 2
[junit4:junit4]   2> 24683 T283 C22 P54610 /update {wt=javabin&version=2} {add=[128 (1428591389150543872)]} 0 1
[junit4:junit4]   2> 24690 T322 C23 P54631 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[128 (1428591389157883904)]} 0 1
[junit4:junit4]   2> 24691 T303 C20 P54622 /update {wt=javabin&version=2} {add=[128]} 0 5
[junit4:junit4]   2> 24694 T285 C22 P54610 /update {wt=javabin&version=2} {add=[129 (1428591389162078208)]} 0 1
[junit4:junit4]   2> 24701 T336 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[129 (1428591389166272512)]} 0 1
[junit4:junit4]   2> 24702 T304 C20 P54622 /update {wt=javabin&version=2} {add=[129 (1428591389166272512)]} 0 5
[junit4:junit4]   2> 24706 T284 C22 P54610 /update {wt=javabin&version=2} {add=[130 (1428591389174661120)]} 0 1
[junit4:junit4]   2> 24713 T318 C23 P54631 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[130 (1428591389182001152)]} 0 1
[junit4:junit4]   2> 24713 T306 C20 P54622 /update {wt=javabin&version=2} {add=[130]} 0 4
[junit4:junit4]   2> 24717 T286 C22 P54610 /update {wt=javabin&version=2} {add=[131 (1428591389186195456)]} 0 1
[junit4:junit4]   2> 24720 T317 C23 P54631 /update {wt=javabin&version=2} {add=[131 (1428591389190389760)]} 0 0
[junit4:junit4]   2> 24724 T282 C22 P54610 /update {wt=javabin&version=2} {add=[132 (1428591389193535488)]} 0 1
[junit4:junit4]   2> 24731 T333 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[132 (1428591389197729792)]} 0 1
[junit4:junit4]   2> 24732 T301 C20 P54622 /update {wt=javabin&version=2} {add=[132 (1428591389197729792)]} 0 5
[junit4:junit4]   2> 24735 T281 C22 P54610 /update {wt=javabin&version=2} {add=[133 (1428591389205069824)]} 0 1
[junit4:junit4]   2> 24744 T335 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[133 (1428591389210312704)]} 0 1
[junit4:junit4]   2> 24745 T302 C20 P54622 /update {wt=javabin&version=2} {add=[133 (1428591389210312704)]} 0 6
[junit4:junit4]   2> 24749 T283 C22 P54610 /update {wt=javabin&version=2} {add=[134 (1428591389219749888)]} 0 2
[junit4:junit4]   2> 24754 T319 C23 P54631 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[134 (1428591389226041344)]} 0 1
[junit4:junit4]   2> 24756 T305 C20 P54622 /update {wt=javabin&version=2} {add=[134]} 0 6
[junit4:junit4]   2> 24760 T285 C22 P54610 /update {wt=javabin&version=2} {add=[135 (1428591389231284224)]} 0 1
[junit4:junit4]   2> 24767 T334 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[135 (1428591389235478528)]} 0 1
[junit4:junit4]   2> 24769 T303 C20 P54622 /update {wt=javabin&version=2} {add=[135 (1428591389235478528)]} 0 6
[junit4:junit4]   2> 24772 T284 C22 P54610 /update {wt=javabin&version=2} {add=[136 (1428591389243867136)]} 0 1
[junit4:junit4]   2> 24776 T320 C23 P54631 /update {wt=javabin&version=2} {add=[136 (1428591389248061440)]} 0 1
[junit4:junit4]   2> 24779 T286 C22 P54610 /update {wt=javabin&version=2} {add=[137 (1428591389251207168)]} 0 1
[junit4:junit4]   2> 24786 T321 C23 P54631 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[137 (1428591389258547200)]} 0 1
[junit4:junit4]   2> 24786 T304 C20 P54622 /update {wt=javabin&version=2} {add=[137]} 0 4
[junit4:junit4]   2> 24791 T282 C22 P54610 /update {wt=javabin&version=2} {add=[138 (1428591389263790080)]} 0 1
[junit4:junit4]   2> 24798 T337 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[138 (1428591389267984384)]} 0 1
[junit4:junit4]   2> 24799 T306 C20 P54622 /update {wt=javabin&version=2} {add=[138 (1428591389267984384)]} 0 5
[junit4:junit4]   2> 24802 T283 C22 P54610 /update {wt=javabin&version=2} {add=[139 (1428591389276372992)]} 0 0
[junit4:junit4]   2> 24808 T322 C23 P54631 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[139 (1428591389281615872)]} 0 1
[junit4:junit4]   2> 24809 T301 C20 P54622 /update {wt=javabin&version=2} {add=[139]} 0 3
[junit4:junit4]   2> 24812 T285 C22 P54610 /update {wt=javabin&version=2} {add=[140 (1428591389286858752)]} 0 0
[junit4:junit4]   2> 24817 T317 C23 P54631 /update {wt=javabin&version=2} {add=[140 (1428591389291053056)]} 0 1
[junit4:junit4]   2> 24820 T284 C22 P54610 /update {wt=javabin&version=2} {add=[141 (1428591389294198784)]} 0 1
[junit4:junit4]   2> 24826 T319 C23 P54631 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[141 (1428591389301538816)]} 0 0
[junit4:junit4]   2> 24827 T305 C20 P54622 /update {wt=javabin&version=2} {add=[141]} 0 4
[junit4:junit4]   2> 24832 T286 C22 P54610 /update {wt=javabin&version=2} {add=[142 (1428591389306781696)]} 0 1
[junit4:junit4]   2> 24837 T320 C23 P54631 /update {wt=javabin&version=2} {add=[142 (1428591389312024576)]} 0 1
[junit4:junit4]   2> 24852 T282 C22 P54610 /update {wt=javabin&version=2} {add=[143 (1428591389315170304)]} 0 13
[junit4:junit4]   2> 24857 T321 C23 P54631 /update {wt=javabin&version=2} {add=[143 (1428591389332996096)]} 0 1
[junit4:junit4]   2> 24861 T281 C22 P54610 /update {wt=javabin&version=2} {add=[144 (1428591389337190400)]} 0 1
[junit4:junit4]   2> 24866 T322 C23 P54631 /update {wt=javabin&version=2} {add=[144 (1428591389342433280)]} 0 1
[junit4:junit4]   2> 24869 T283 C22 P54610 /update {wt=javabin&version=2} {add=[145 (1428591389345579008)]} 0 1
[junit4:junit4]   2> 24874 T318 C23 P54631 /update {wt=javabin&version=2} {add=[145 (1428591389351870464)]} 0 0
[junit4:junit4]   2> 24878 T285 C22 P54610 /update {wt=javabin&version=2} {add=[146 (1428591389355016192)]} 0 1
[junit4:junit4]   2> 24886 T338 C19 P54640 /update {distrib.from=http://127.0.0.1:54622/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[146 (1428591389359210496)]} 0

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

-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3\index
[junit4:junit4]   2> 91313 T342 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3
[junit4:junit4]   2> 91314 T342 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3\index
[junit4:junit4]   2> 91315 T342 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3
[junit4:junit4]   2> 91322 T342 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=5,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=36,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 91323 T342 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 91324 T342 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 91324 T342 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 91332 T342 C19 P54640 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3\index
[junit4:junit4]   2> 91334 T342 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 91336 T342 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3\index
[junit4:junit4]   2> 91336 T342 oasc.CachingDirectoryFactory.close Closing directory when closing factory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3\index
[junit4:junit4]   2> 91337 T342 oasc.CachingDirectoryFactory.closeDirectory Closing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3\index
[junit4:junit4]   2> 91337 T342 oasc.CachingDirectoryFactory.close Closing directory when closing factory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3
[junit4:junit4]   2> 91337 T342 oasc.CachingDirectoryFactory.closeDirectory Closing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3
[junit4:junit4]   2> 91338 T342 oasc.CachingDirectoryFactory.close Closing directory when closing factory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3\index.20130304152833996
[junit4:junit4]   2> 91338 T342 oasc.CachingDirectoryFactory.closeDirectory Closing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.BasicDistributedZk2Test-1362410891797\jetty3\index.20130304152833996
[junit4:junit4]   2> 91339 T342 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 91340 T342 oasc.LeaderElector$1.process WARNING  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election/89286960205594634-4-n_0000000001
[junit4:junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4:junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4:junit4]   2> 	at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:153)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:150)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:150)
[junit4:junit4]   2> 	at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:63)
[junit4:junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:243)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:156)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:100)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4]   2> 
[junit4:junit4]   2> 91342 T342 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> 91342 T342 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 91342 T342 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 91342 T342 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> 91343 T342 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 91344 T342 oasc.LeaderElector$1.process WARNING  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4:junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4:junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4:junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:236)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:233)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:233)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4]   2> 
[junit4:junit4]   2> 91344 T342 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> NOTE: test params are: codec=Lucene41, sim=DefaultSimilarity, locale=ga, timezone=Atlantic/Madeira
[junit4:junit4]   2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_15 (64-bit)/cpus=2,threads=2,free=61862976,total=134217728
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestOmitPositions, XmlUpdateRequestHandlerTest, EchoParamsTest, UniqFieldsUpdateProcessorFactoryTest, TestDistributedGrouping, XsltUpdateRequestHandlerTest, DocumentAnalysisRequestHandlerTest, TestSort, TestSystemIdResolver, TestSolrDeletionPolicy1, SolrIndexConfigTest, TestRemoteStreaming, SuggesterTest, LoggingHandlerTest, SearchHandlerTest, ClusterStateUpdateTest, BasicDistributedZk2Test]
[junit4:junit4] Completed in 91.47s, 1 test, 1 error <<< FAILURES!

[...truncated 770 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:381: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:361: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:183: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:449: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1213: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:877: There were test failures: 261 suites, 1101 tests, 1 error, 18 ignored (12 assumptions)

Total time: 58 minutes 43 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 64bit/jdk1.7.0_15 -XX:+UseG1GC
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message