lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-Tests-trunk-Java6 - Build # 15965 - Failure
Date Fri, 01 Mar 2013 13:37:06 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java6/15965/

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([60FA6B95D299E8EF:E11CE58DA5C688D3]: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:616)
	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:679)




Build Log:
[...truncated 8880 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 1 T2834 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4]   2> 5 T2834 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362144572050
[junit4:junit4]   2> 6 T2834 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 7 T2835 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 10 T2835 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 10 T2835 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4]   2> 10 T2835 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4]   2> 10 T2835 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 11 T2835 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4]   2> 107 T2834 oasc.ZkTestServer.run start zk server on port:35473
[junit4:junit4]   2> 107 T2834 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35473 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@608ffb7e
[junit4:junit4]   2> 108 T2834 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 108 T2840 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:35473. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 109 T2840 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35473, initiating session
[junit4:junit4]   2> 109 T2836 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:35474
[junit4:junit4]   2> 110 T2836 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:35474
[junit4:junit4]   2> 110 T2838 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 113 T2838 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d2624b2980000 with negotiated timeout 10000 for client /140.211.11.196:35474
[junit4:junit4]   2> 113 T2840 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:35473, sessionid = 0x13d2624b2980000, negotiated timeout = 10000
[junit4:junit4]   2> 114 T2841 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@608ffb7e name:ZooKeeperConnection Watcher:127.0.0.1:35473 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 114 T2834 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 114 T2834 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 129 T2839 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d2624b2980000
[junit4:junit4]   2> 134 T2841 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 135 T2836 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:35474 which had sessionid 0x13d2624b2980000
[junit4:junit4]   2> 134 T2834 oaz.ZooKeeper.close Session: 0x13d2624b2980000 closed
[junit4:junit4]   2> 135 T2834 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35473/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@70ecc331
[junit4:junit4]   2> 136 T2834 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 137 T2842 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:35473. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 137 T2842 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35473, initiating session
[junit4:junit4]   2> 138 T2836 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:35475
[junit4:junit4]   2> 138 T2836 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:35475
[junit4:junit4]   2> 140 T2838 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d2624b2980001 with negotiated timeout 10000 for client /140.211.11.196:35475
[junit4:junit4]   2> 140 T2842 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:35473, sessionid = 0x13d2624b2980001, negotiated timeout = 10000
[junit4:junit4]   2> 140 T2843 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@70ecc331 name:ZooKeeperConnection Watcher:127.0.0.1:35473/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 140 T2834 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 141 T2834 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 152 T2834 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 155 T2834 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 163 T2834 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 166 T2834 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 167 T2834 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 178 T2834 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 179 T2834 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 282 T2834 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 283 T2834 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 286 T2834 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 287 T2834 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 295 T2834 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 296 T2834 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 299 T2834 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 300 T2834 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 303 T2834 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 303 T2834 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 306 T2834 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 307 T2834 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 314 T2834 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 315 T2834 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 317 T2839 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d2624b2980001
[junit4:junit4]   2> 318 T2843 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 318 T2834 oaz.ZooKeeper.close Session: 0x13d2624b2980001 closed
[junit4:junit4]   2> 318 T2836 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:35475 which had sessionid 0x13d2624b2980001
[junit4:junit4]   2> 507 T2834 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 510 T2834 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:35476
[junit4:junit4]   2> 510 T2834 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 511 T2834 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 511 T2834 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362144572363
[junit4:junit4]   2> 512 T2834 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362144572363/solr.xml
[junit4:junit4]   2> 512 T2834 oasc.CoreContainer.<init> New CoreContainer 494399757
[junit4:junit4]   2> 513 T2834 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362144572363/'
[junit4:junit4]   2> 513 T2834 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362144572363/'
[junit4:junit4]   2> 566 T2834 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 566 T2834 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 567 T2834 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 567 T2834 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 567 T2834 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 568 T2834 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 568 T2834 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 569 T2834 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 569 T2834 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 570 T2834 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 592 T2834 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 611 T2834 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:35473/solr
[junit4:junit4]   2> 612 T2834 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 612 T2834 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35473 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@3f452f77
[junit4:junit4]   2> 613 T2834 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 614 T2853 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:35473. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 614 T2853 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35473, initiating session
[junit4:junit4]   2> 614 T2836 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:35477
[junit4:junit4]   2> 615 T2836 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:35477
[junit4:junit4]   2> 617 T2838 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d2624b2980002 with negotiated timeout 20000 for client /140.211.11.196:35477
[junit4:junit4]   2> 617 T2853 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:35473, sessionid = 0x13d2624b2980002, negotiated timeout = 20000
[junit4:junit4]   2> 617 T2854 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3f452f77 name:ZooKeeperConnection Watcher:127.0.0.1:35473 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 617 T2834 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 618 T2839 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d2624b2980002
[junit4:junit4]   2> 626 T2854 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 626 T2836 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:35477 which had sessionid 0x13d2624b2980002
[junit4:junit4]   2> 626 T2834 oaz.ZooKeeper.close Session: 0x13d2624b2980002 closed
[junit4:junit4]   2> 627 T2834 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 638 T2834 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35473/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@4fb6f9ad
[junit4:junit4]   2> 639 T2834 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 639 T2855 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:35473. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 640 T2855 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35473, initiating session
[junit4:junit4]   2> 640 T2836 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:35478
[junit4:junit4]   2> 640 T2836 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:35478
[junit4:junit4]   2> 642 T2838 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d2624b2980003 with negotiated timeout 20000 for client /140.211.11.196:35478
[junit4:junit4]   2> 642 T2855 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:35473, sessionid = 0x13d2624b2980003, negotiated timeout = 20000
[junit4:junit4]   2> 642 T2856 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4fb6f9ad name:ZooKeeperConnection Watcher:127.0.0.1:35473/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 642 T2834 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 644 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 652 T2834 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 654 T2834 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35476_
[junit4:junit4]   2> 655 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:35476_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:35476_
[junit4:junit4]   2> 656 T2834 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35476_
[junit4:junit4]   2> 659 T2834 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 676 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980003 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> 677 T2834 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 680 T2834 oasc.Overseer.start Overseer (id=89269506674262019-127.0.0.1:35476_-n_0000000000) starting
[junit4:junit4]   2> 680 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 687 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 688 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 695 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 696 T2858 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 696 T2834 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 706 T2834 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 708 T2857 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 712 T2859 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362144572363/collection1
[junit4:junit4]   2> 713 T2859 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 713 T2859 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 713 T2859 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 715 T2859 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362144572363/collection1/'
[junit4:junit4]   2> 716 T2859 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362144572363/collection1/lib/README' to classloader
[junit4:junit4]   2> 716 T2859 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362144572363/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 762 T2859 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 818 T2859 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 918 T2859 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 924 T2859 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1511 T2859 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1522 T2859 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1526 T2859 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1538 T2859 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1543 T2859 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1547 T2859 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1548 T2859 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1549 T2859 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362144572363/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/control/data/
[junit4:junit4]   2> 1549 T2859 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7cbe41ec
[junit4:junit4]   2> 1549 T2859 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 1551 T2859 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/control/data forceNew:false
[junit4:junit4]   2> 1552 T2859 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/control/data
[junit4:junit4]   2> 1552 T2859 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/control/data/index/
[junit4:junit4]   2> 1553 T2859 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1553 T2859 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/control/data/index forceNew:false
[junit4:junit4]   2> 1556 T2859 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5b63f50b lockFactory=org.apache.lucene.store.NativeFSLockFactory@41d5a12f),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1556 T2859 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 1557 T2859 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/control/data/index
[junit4:junit4]   2> 1559 T2859 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1559 T2859 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1560 T2859 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1560 T2859 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1561 T2859 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1561 T2859 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1561 T2859 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1561 T2859 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1562 T2859 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1569 T2859 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1575 T2859 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/control/data
[junit4:junit4]   2> 1575 T2859 oass.SolrIndexSearcher.<init> Opening Searcher@7a59e653 main
[junit4:junit4]   2> 1575 T2859 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/control/data/tlog
[junit4:junit4]   2> 1576 T2859 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1577 T2859 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1579 T2860 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7a59e653 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1581 T2859 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 1581 T2859 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1584 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980003 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> 1604 T1405 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 2211 T2857 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2212 T2857 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:35476_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:35476"}
[junit4:junit4]   2> 2212 T2857 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 2212 T2857 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 2212 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980003 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> 2227 T2856 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> 2597 T2859 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 2597 T2859 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:35476 collection:control_collection shard:shard1
[junit4:junit4]   2> 2598 T2859 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 2613 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980003 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> 2614 T2859 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 2615 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980003 type:create cxid:0x73 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2625 T2859 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2625 T2859 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2625 T2859 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:35476/collection1/
[junit4:junit4]   2> 2625 T2859 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 2625 T2859 oasc.SyncStrategy.syncToMe http://127.0.0.1:35476/collection1/ has no replicas
[junit4:junit4]   2> 2626 T2859 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:35476/collection1/
[junit4:junit4]   2> 2626 T2859 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 2630 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980003 type:create cxid:0x7d zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3352 T1413 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 3731 T2857 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3752 T2856 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> 3762 T2859 oasc.ZkController.register We are http://127.0.0.1:35476/collection1/ and leader is http://127.0.0.1:35476/collection1/
[junit4:junit4]   2> 3762 T2859 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35476
[junit4:junit4]   2> 3762 T2859 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 3762 T2859 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 3762 T2859 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 3764 T2859 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3765 T2834 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 3765 T2834 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 3766 T2834 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 3779 T2834 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 3780 T2834 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35473/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@5cb65f51
[junit4:junit4]   2> 3781 T2834 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3781 T2861 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:35473. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 3782 T2861 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35473, initiating session
[junit4:junit4]   2> 3782 T2836 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:35482
[junit4:junit4]   2> 3782 T2836 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:35482
[junit4:junit4]   2> 3783 T2838 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d2624b2980004 with negotiated timeout 10000 for client /140.211.11.196:35482
[junit4:junit4]   2> 3783 T2861 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:35473, sessionid = 0x13d2624b2980004, negotiated timeout = 10000
[junit4:junit4]   2> 3784 T2862 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5cb65f51 name:ZooKeeperConnection Watcher:127.0.0.1:35473/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3784 T2834 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3785 T2834 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3786 T2834 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 3956 T2834 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 3959 T2834 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:35483
[junit4:junit4]   2> 3960 T2834 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 3960 T2834 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3961 T2834 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362144575830
[junit4:junit4]   2> 3961 T2834 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362144575830/solr.xml
[junit4:junit4]   2> 3961 T2834 oasc.CoreContainer.<init> New CoreContainer 1110190870
[junit4:junit4]   2> 3962 T2834 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362144575830/'
[junit4:junit4]   2> 3962 T2834 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362144575830/'
[junit4:junit4]   2> 4008 T2834 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 4008 T2834 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 4009 T2834 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 4009 T2834 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 4010 T2834 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 4010 T2834 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 4010 T2834 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 4011 T2834 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 4011 T2834 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 4012 T2834 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 4030 T2834 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 4047 T2834 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:35473/solr
[junit4:junit4]   2> 4048 T2834 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 4048 T2834 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35473 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@3a6fd169
[junit4:junit4]   2> 4049 T2834 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4049 T2872 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:35473. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 4050 T2872 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35473, initiating session
[junit4:junit4]   2> 4050 T2836 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:35484
[junit4:junit4]   2> 4051 T2836 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:35484
[junit4:junit4]   2> 4052 T2838 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d2624b2980005 with negotiated timeout 20000 for client /140.211.11.196:35484
[junit4:junit4]   2> 4052 T2872 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:35473, sessionid = 0x13d2624b2980005, negotiated timeout = 20000
[junit4:junit4]   2> 4053 T2873 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a6fd169 name:ZooKeeperConnection Watcher:127.0.0.1:35473 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4053 T2834 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4054 T2839 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d2624b2980005
[junit4:junit4]   2> 4055 T2873 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 4055 T2836 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:35484 which had sessionid 0x13d2624b2980005
[junit4:junit4]   2> 4055 T2834 oaz.ZooKeeper.close Session: 0x13d2624b2980005 closed
[junit4:junit4]   2> 4055 T2834 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 4064 T2834 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35473/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@29e7287d
[junit4:junit4]   2> 4065 T2834 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4066 T2874 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:35473. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 4066 T2874 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35473, initiating session
[junit4:junit4]   2> 4066 T2836 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:35485
[junit4:junit4]   2> 4067 T2836 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:35485
[junit4:junit4]   2> 4068 T2838 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d2624b2980006 with negotiated timeout 20000 for client /140.211.11.196:35485
[junit4:junit4]   2> 4068 T2874 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:35473, sessionid = 0x13d2624b2980006, negotiated timeout = 20000
[junit4:junit4]   2> 4068 T2875 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29e7287d name:ZooKeeperConnection Watcher:127.0.0.1:35473/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4068 T2834 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4069 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980006 type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4070 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980006 type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4072 T2834 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4990 T1423 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 5074 T2834 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35483_
[junit4:junit4]   2> 5075 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980006 type:delete cxid:0x9 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:35483_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:35483_
[junit4:junit4]   2> 5076 T2834 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35483_
[junit4:junit4]   2> 5078 T2856 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> 5079 T2875 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5079 T2862 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5088 T2856 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5094 T2876 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362144575830/collection1
[junit4:junit4]   2> 5094 T2876 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 5095 T2876 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 5095 T2876 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 5096 T2876 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362144575830/collection1/'
[junit4:junit4]   2> 5097 T2876 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362144575830/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 5098 T2876 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362144575830/collection1/lib/README' to classloader
[junit4:junit4]   2> 5143 T2876 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 5200 T2876 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 5258 T2857 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5259 T2857 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:35476_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:35476"}
[junit4:junit4]   2> 5263 T2856 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> 5263 T2862 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> 5301 T2876 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 5301 T2875 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> 5307 T2876 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 5882 T2876 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 5892 T2876 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 5896 T2876 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 5908 T2876 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5912 T2876 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5915 T2876 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5916 T2876 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5917 T2876 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362144575830/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty1/
[junit4:junit4]   2> 5918 T2876 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7cbe41ec
[junit4:junit4]   2> 5918 T2876 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 5920 T2876 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty1 forceNew:false
[junit4:junit4]   2> 5920 T2876 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty1
[junit4:junit4]   2> 5920 T2876 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty1/index/
[junit4:junit4]   2> 5921 T2876 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 5921 T2876 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty1/index forceNew:false
[junit4:junit4]   2> 5923 T2876 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@629efc6a lockFactory=org.apache.lucene.store.NativeFSLockFactory@a70928f),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 5924 T2876 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 5924 T2876 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty1/index
[junit4:junit4]   2> 5926 T2876 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 5926 T2876 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 5927 T2876 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 5927 T2876 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 5928 T2876 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 5928 T2876 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 5928 T2876 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 5929 T2876 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 5929 T2876 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 5936 T2876 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 5941 T2876 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty1
[junit4:junit4]   2> 5941 T2876 oass.SolrIndexSearcher.<init> Opening Searcher@76bcc74a main
[junit4:junit4]   2> 5942 T2876 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty1/tlog
[junit4:junit4]   2> 5942 T2876 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 5943 T2876 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 5947 T2877 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@76bcc74a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 5949 T2876 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 5949 T2876 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 6726 T1431 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 6778 T2857 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6779 T2857 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:35483_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:35483"}
[junit4:junit4]   2> 6779 T2857 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4]   2> 6779 T2857 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 6792 T2875 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> 6792 T2862 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> 6792 T2856 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> 6951 T2876 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 6951 T2876 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:35483 collection:collection1 shard:shard1
[junit4:junit4]   2> 6952 T2876 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 6967 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980006 type:delete cxid:0x46 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 6968 T2876 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 6968 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980006 type:create cxid:0x47 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6979 T2876 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 6979 T2876 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 6979 T2876 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:35483/collection1/
[junit4:junit4]   2> 6979 T2876 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 6980 T2876 oasc.SyncStrategy.syncToMe http://127.0.0.1:35483/collection1/ has no replicas
[junit4:junit4]   2> 6980 T2876 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:35483/collection1/
[junit4:junit4]   2> 6980 T2876 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 6984 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980006 type:create cxid:0x51 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8295 T2857 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8328 T2856 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> 8328 T2875 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> 8328 T2862 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> 8363 T2876 oasc.ZkController.register We are http://127.0.0.1:35483/collection1/ and leader is http://127.0.0.1:35483/collection1/
[junit4:junit4]   2> 8363 T2876 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35483
[junit4:junit4]   2> 8363 T2876 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 8363 T2876 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 8363 T2876 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 8365 T2876 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8366 T2834 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 8367 T2834 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 8367 T2834 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 8377 T1439 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 8551 T2834 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 8554 T2834 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:35489
[junit4:junit4]   2> 8554 T2834 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 8555 T2834 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8555 T2834 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362144580424
[junit4:junit4]   2> 8556 T2834 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362144580424/solr.xml
[junit4:junit4]   2> 8556 T2834 oasc.CoreContainer.<init> New CoreContainer 1431263252
[junit4:junit4]   2> 8557 T2834 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362144580424/'
[junit4:junit4]   2> 8557 T2834 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362144580424/'
[junit4:junit4]   2> 8603 T2834 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 8603 T2834 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 8604 T2834 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 8604 T2834 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 8605 T2834 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 8605 T2834 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 8605 T2834 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 8606 T2834 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 8606 T2834 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 8607 T2834 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 8625 T2834 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 8642 T2834 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:35473/solr
[junit4:junit4]   2> 8643 T2834 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 8643 T2834 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35473 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@359725c6
[junit4:junit4]   2> 8644 T2834 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8645 T2887 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:35473. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 8645 T2887 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35473, initiating session
[junit4:junit4]   2> 8646 T2836 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:35490
[junit4:junit4]   2> 8646 T2836 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:35490
[junit4:junit4]   2> 8652 T2838 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d2624b2980007 with negotiated timeout 20000 for client /140.211.11.196:35490
[junit4:junit4]   2> 8652 T2887 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:35473, sessionid = 0x13d2624b2980007, negotiated timeout = 20000
[junit4:junit4]   2> 8652 T2888 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@359725c6 name:ZooKeeperConnection Watcher:127.0.0.1:35473 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8652 T2834 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8653 T2839 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d2624b2980007
[junit4:junit4]   2> 8654 T2888 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 8654 T2836 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:35490 which had sessionid 0x13d2624b2980007
[junit4:junit4]   2> 8654 T2834 oaz.ZooKeeper.close Session: 0x13d2624b2980007 closed
[junit4:junit4]   2> 8655 T2834 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 8664 T2834 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35473/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@6ecae26d
[junit4:junit4]   2> 8665 T2834 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8665 T2889 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:35473. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 8666 T2889 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35473, initiating session
[junit4:junit4]   2> 8666 T2836 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:35491
[junit4:junit4]   2> 8666 T2836 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:35491
[junit4:junit4]   2> 8667 T2838 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d2624b2980008 with negotiated timeout 20000 for client /140.211.11.196:35491
[junit4:junit4]   2> 8667 T2889 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:35473, sessionid = 0x13d2624b2980008, negotiated timeout = 20000
[junit4:junit4]   2> 8668 T2890 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6ecae26d name:ZooKeeperConnection Watcher:127.0.0.1:35473/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8668 T2834 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8669 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980008 type:create cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8670 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980008 type:create cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8678 T2834 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9681 T2834 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35489_
[junit4:junit4]   2> 9682 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980008 type:delete cxid:0x9 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:35489_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:35489_
[junit4:junit4]   2> 9683 T2834 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35489_
[junit4:junit4]   2> 9686 T2856 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> 9686 T2875 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9686 T2890 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9686 T2862 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9686 T2875 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> 9687 T2862 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> 9687 T2856 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9694 T2891 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362144580424/collection1
[junit4:junit4]   2> 9694 T2891 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 9695 T2891 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 9695 T2891 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 9696 T2891 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362144580424/collection1/'
[junit4:junit4]   2> 9697 T2891 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362144580424/collection1/lib/README' to classloader
[junit4:junit4]   2> 9698 T2891 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362144580424/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 9747 T2891 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 9808 T2891 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 9843 T2857 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9844 T2857 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:35483_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:35483"}
[junit4:junit4]   2> 9848 T2875 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> 9848 T2856 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> 9848 T2862 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> 9909 T2891 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 9909 T2890 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> 9915 T2891 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 10109 T1447 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 10535 T2891 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 10546 T2891 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 10550 T2891 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 10562 T2891 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10567 T2891 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10571 T2891 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10572 T2891 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10573 T2891 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362144580424/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty2/
[junit4:junit4]   2> 10573 T2891 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7cbe41ec
[junit4:junit4]   2> 10574 T2891 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 10575 T2891 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty2 forceNew:false
[junit4:junit4]   2> 10576 T2891 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty2
[junit4:junit4]   2> 10576 T2891 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty2/index/
[junit4:junit4]   2> 10577 T2891 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 10577 T2891 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty2/index forceNew:false
[junit4:junit4]   2> 10579 T2891 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@12f7296e lockFactory=org.apache.lucene.store.NativeFSLockFactory@5e838fb0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10580 T2891 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 10580 T2891 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty2/index
[junit4:junit4]   2> 10582 T2891 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 10583 T2891 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 10583 T2891 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 10584 T2891 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 10584 T2891 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 10584 T2891 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 10585 T2891 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 10585 T2891 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 10586 T2891 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 10593 T2891 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 10598 T2891 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty2
[junit4:junit4]   2> 10599 T2891 oass.SolrIndexSearcher.<init> Opening Searcher@5ad8c0d5 main
[junit4:junit4]   2> 10599 T2891 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty2/tlog
[junit4:junit4]   2> 10600 T2891 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 10600 T2891 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 10604 T2892 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5ad8c0d5 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 10606 T2891 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 10606 T2891 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 11361 T2857 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11362 T2857 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:35489_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:35489"}
[junit4:junit4]   2> 11362 T2857 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 11362 T2857 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4]   2> 11367 T2856 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> 11367 T2890 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> 11367 T2862 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> 11367 T2875 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> 11609 T2891 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 11609 T2891 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:35489 collection:collection1 shard:shard2
[junit4:junit4]   2> 11610 T2891 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 11623 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980008 type:delete cxid:0x45 zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard2 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard2
[junit4:junit4]   2> 11624 T2891 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 11624 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980008 type:create cxid:0x46 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 11626 T2891 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 11626 T2891 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 11627 T2891 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:35489/collection1/
[junit4:junit4]   2> 11627 T2891 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 11627 T2891 oasc.SyncStrategy.syncToMe http://127.0.0.1:35489/collection1/ has no replicas
[junit4:junit4]   2> 11627 T2891 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:35489/collection1/
[junit4:junit4]   2> 11627 T2891 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 11636 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980008 type:create cxid:0x4f zxid:0x82 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 11747 T1455 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 12880 T2857 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13050 T2875 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> 13050 T2862 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> 13050 T2890 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> 13050 T2856 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> 13119 T2891 oasc.ZkController.register We are http://127.0.0.1:35489/collection1/ and leader is http://127.0.0.1:35489/collection1/
[junit4:junit4]   2> 13119 T2891 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35489
[junit4:junit4]   2> 13119 T2891 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 13119 T2891 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 13119 T2891 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 13121 T2891 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13122 T2834 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 13123 T2834 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 13123 T2834 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 13306 T2834 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 13309 T2834 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:35495
[junit4:junit4]   2> 13310 T2834 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 13310 T2834 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 13311 T2834 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362144585180
[junit4:junit4]   2> 13311 T2834 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362144585180/solr.xml
[junit4:junit4]   2> 13311 T2834 oasc.CoreContainer.<init> New CoreContainer 469635303
[junit4:junit4]   2> 13312 T2834 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362144585180/'
[junit4:junit4]   2> 13312 T2834 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362144585180/'
[junit4:junit4]   2> 13358 T2834 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 13358 T2834 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 13359 T2834 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 13359 T2834 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 13360 T2834 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 13360 T2834 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 13360 T2834 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 13361 T2834 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 13361 T2834 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 13362 T2834 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 13380 T1461 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 13380 T2834 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 13397 T2834 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:35473/solr
[junit4:junit4]   2> 13398 T2834 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 13398 T2834 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35473 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@7ecadb3b
[junit4:junit4]   2> 13399 T2834 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 13400 T2902 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:35473. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 13400 T2902 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35473, initiating session
[junit4:junit4]   2> 13401 T2836 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:35496
[junit4:junit4]   2> 13401 T2836 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:35496
[junit4:junit4]   2> 13403 T2838 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d2624b2980009 with negotiated timeout 20000 for client /140.211.11.196:35496
[junit4:junit4]   2> 13403 T2902 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:35473, sessionid = 0x13d2624b2980009, negotiated timeout = 20000
[junit4:junit4]   2> 13403 T2903 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ecadb3b name:ZooKeeperConnection Watcher:127.0.0.1:35473 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 13404 T2834 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 13405 T2839 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d2624b2980009
[junit4:junit4]   2> 13405 T2903 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 13406 T2836 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:35496 which had sessionid 0x13d2624b2980009
[junit4:junit4]   2> 13405 T2834 oaz.ZooKeeper.close Session: 0x13d2624b2980009 closed
[junit4:junit4]   2> 13406 T2834 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 13415 T2834 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35473/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@32d4c3a8
[junit4:junit4]   2> 13416 T2834 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 13416 T2904 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:35473. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 13417 T2904 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35473, initiating session
[junit4:junit4]   2> 13417 T2836 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:35497
[junit4:junit4]   2> 13417 T2836 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:35497
[junit4:junit4]   2> 13418 T2838 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d2624b298000a with negotiated timeout 20000 for client /140.211.11.196:35497
[junit4:junit4]   2> 13418 T2904 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:35473, sessionid = 0x13d2624b298000a, negotiated timeout = 20000
[junit4:junit4]   2> 13419 T2905 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32d4c3a8 name:ZooKeeperConnection Watcher:127.0.0.1:35473/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 13419 T2834 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 13420 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b298000a type:create cxid:0x1 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 13421 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b298000a type:create cxid:0x2 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 13430 T2834 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 14432 T2834 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35495_
[junit4:junit4]   2> 14433 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b298000a type:delete cxid:0x9 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:35495_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:35495_
[junit4:junit4]   2> 14435 T2834 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35495_
[junit4:junit4]   2> 14437 T2890 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> 14437 T2856 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> 14437 T2862 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14437 T2905 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14438 T2862 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> 14437 T2875 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14438 T2875 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> 14439 T2890 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14439 T2856 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14452 T2906 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362144585180/collection1
[junit4:junit4]   2> 14452 T2906 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 14453 T2906 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 14453 T2906 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 14454 T2906 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362144585180/collection1/'
[junit4:junit4]   2> 14455 T2906 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362144585180/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 14456 T2906 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362144585180/collection1/lib/README' to classloader
[junit4:junit4]   2> 14505 T2906 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 14570 T2906 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 14572 T2857 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14573 T2857 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:35489_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:35489"}
[junit4:junit4]   2> 14578 T2856 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> 14578 T2862 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> 14578 T2890 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> 14578 T2875 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> 14671 T2906 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 14671 T2905 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> 14677 T2906 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 15010 T1471 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 15275 T2906 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 15285 T2906 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 15289 T2906 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 15301 T2906 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 15305 T2906 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 15309 T2906 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 15310 T2906 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 15311 T2906 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362144585180/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/
[junit4:junit4]   2> 15311 T2906 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7cbe41ec
[junit4:junit4]   2> 15312 T2906 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 15313 T2906 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3 forceNew:false
[junit4:junit4]   2> 15314 T2906 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3
[junit4:junit4]   2> 15314 T2906 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/index/
[junit4:junit4]   2> 15314 T2906 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 15315 T2906 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/index forceNew:false
[junit4:junit4]   2> 15317 T2906 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@57ee1ab0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@13e3ed98),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 15317 T2906 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 15318 T2906 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/index
[junit4:junit4]   2> 15320 T2906 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 15320 T2906 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 15320 T2906 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 15321 T2906 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 15321 T2906 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 15322 T2906 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 15322 T2906 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 15322 T2906 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 15323 T2906 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 15329 T2906 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 15335 T2906 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3
[junit4:junit4]   2> 15335 T2906 oass.SolrIndexSearcher.<init> Opening Searcher@44d93a51 main
[junit4:junit4]   2> 15335 T2906 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/tlog
[junit4:junit4]   2> 15336 T2906 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 15336 T2906 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 15341 T2907 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@44d93a51 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 15342 T2906 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 15343 T2906 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 16093 T2857 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16094 T2857 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:35495_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:35495"}
[junit4:junit4]   2> 16094 T2857 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 16094 T2857 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 16106 T2856 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> 16109 T2875 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> 16109 T2905 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> 16106 T2862 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> 16106 T2890 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> 16345 T2906 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 16345 T2906 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:35495 collection:collection1 shard:shard1
[junit4:junit4]   2> 16351 T2906 oasc.ZkController.register We are http://127.0.0.1:35495/collection1/ and leader is http://127.0.0.1:35483/collection1/
[junit4:junit4]   2> 16352 T2906 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35495
[junit4:junit4]   2> 16352 T2906 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 16352 T2906 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C162 name=collection1 org.apache.solr.core.SolrCore@6ee7830e url=http://127.0.0.1:35495/collection1 node=127.0.0.1:35495_ C162_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:35495_, base_url=http://127.0.0.1:35495}
[junit4:junit4]   2> 16353 T2908 C162 P35495 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 16353 T2906 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16354 T2908 C162 P35495 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 16354 T2908 C162 P35495 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 16354 T2908 C162 P35495 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 16354 T2834 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 16355 T2834 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 16356 T2834 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 16358 T2908 C162 P35495 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 16378 T2834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16379 T2834 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 16391 T2866 oasc.CoreContainer.create Creating SolrCore 'onenodecollectioncore' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362144575830/onenodecollectioncore
[junit4:junit4]   2> 16392 T2866 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4]   2> 16392 T2866 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4]   2> 16393 T2866 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4]   2> 16394 T2866 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4]   2> 16394 T2866 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4]   2> 16397 T2866 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4]   2> 16398 T2866 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362144575830/onenodecollectioncore/'
[junit4:junit4]   2> 16457 T2866 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 16510 T2866 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 16611 T2866 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 16616 T2866 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 17177 T2866 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 17184 T2866 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 17187 T2866 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 17198 T2866 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 17201 T2866 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 17204 T2866 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 17205 T2866 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 17206 T2866 oasc.SolrCore.<init> [onenodecollectioncore] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362144575830/onenodecollectioncore/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362144572050/onenodecollection/
[junit4:junit4]   2> 17206 T2866 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7cbe41ec
[junit4:junit4]   2> 17207 T2866 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 17208 T2866 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362144572050/onenodecollection forceNew:false
[junit4:junit4]   2> 17208 T2866 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362144572050/onenodecollection
[junit4:junit4]   2> 17209 T2866 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362144572050/onenodecollection/index/
[junit4:junit4]   2> 17209 T2866 oasc.SolrCore.initIndex WARNING [onenodecollectioncore] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362144572050/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 17209 T2866 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362144572050/onenodecollection/index forceNew:false
[junit4:junit4]   2> 17211 T2866 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5575b2b5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5cd5fcdc),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 17211 T2866 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 17212 T2866 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362144572050/onenodecollection/index
[junit4:junit4]   2> 17213 T2866 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 17214 T2866 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 17214 T2866 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 17215 T2866 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 17215 T2866 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 17215 T2866 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 17215 T2866 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 17216 T2866 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 17216 T2866 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 17221 T1488 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 17221 T2866 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 17225 T2866 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362144572050/onenodecollection
[junit4:junit4]   2> 17225 T2866 oass.SolrIndexSearcher.<init> Opening Searcher@28c08f61 main
[junit4:junit4]   2> 17225 T2866 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362144572050/onenodecollection/tlog
[junit4:junit4]   2> 17226 T2866 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 17226 T2866 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 17228 T2866 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362144572050/onenodecollection
[junit4:junit4]   2> 17229 T2909 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@28c08f61 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 17229 T2866 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4]   2> 17613 T2857 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 17614 T2857 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:35495_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:35495"}
[junit4:junit4]   2> 17617 T2857 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:35483_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:35483"}
[junit4:junit4]   2> 17617 T2857 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4]   2> 17617 T2857 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 17627 T2856 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> 17627 T2905 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> 17627 T2875 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> 17627 T2890 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> 17627 T2862 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> 18233 T2866 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4]   2> 18233 T2866 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:35483 collection:onenodecollection shard:shard1
[junit4:junit4]   2> 18234 T2866 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4]   2> 18250 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980006 type:delete cxid:0x9f zxid:0xac txntype:-1 reqpath:n/a Error Path:/solr/collections/onenodecollection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/onenodecollection/leaders
[junit4:junit4]   2> 18251 T2866 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 18251 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980006 type:create cxid:0xa0 zxid:0xad txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 18261 T2866 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 18261 T2866 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 18261 T2866 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:35483/onenodecollectioncore/
[junit4:junit4]   2> 18262 T2866 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 18262 T2866 oasc.SyncStrategy.syncToMe http://127.0.0.1:35483/onenodecollectioncore/ has no replicas
[junit4:junit4]   2> 18262 T2866 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:35483/onenodecollectioncore/
[junit4:junit4]   2> 18262 T2866 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4]   2> 18266 T2839 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d2624b2980006 type:create cxid:0xaa zxid:0xb1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 19138 T2857 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19153 T2856 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> 19153 T2862 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> 19153 T2890 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> 19153 T2875 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> 19153 T2905 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> 19186 T2866 oasc.ZkController.register We are http://127.0.0.1:35483/onenodecollectioncore/ and leader is http://127.0.0.1:35483/onenodecollectioncore/
[junit4:junit4]   2> 19186 T2866 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:35483
[junit4:junit4]   2> 19186 T2866 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 19187 T2866 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4]   2> 19188 T2866 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19190 T2834 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4]   2> 19190 T2834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20193 T2834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C162_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:35495_, base_url=http://127.0.0.1:35495}
[junit4:junit4]   2> 20382 T2908 C162 P35495 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:35483/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 20382 T2908 C162 P35495 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35495 START replicas=[http://127.0.0.1:35483/collection1/] nUpdates=100
[junit4:junit4]   2> 20383 T2908 C162 P35495 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 20383 T2908 C162 P35495 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 20383 T2908 C162 P35495 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 20383 T2908 C162 P35495 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 20383 T2908 C162 P35495 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 20384 T2908 C162 P35495 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:35483/collection1/. core=collection1
[junit4:junit4]   2> 20384 T2908 C162 P35495 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C163 name=collection1 org.apache.solr.core.SolrCore@205bcedb url=http://127.0.0.1:35483/collection1 node=127.0.0.1:35483_ C163_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:35483_, base_url=http://127.0.0.1:35483, leader=true}
[junit4:junit4]   2> 20390 T2867 C163 P35483 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20399 T2868 C163 P35483 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 20399 T2868 C163 P35483 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty1
[junit4:junit4]   2> 20401 T2868 C163 P35483 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@629efc6a lockFactory=org.apache.lucene.store.NativeFSLockFactory@a70928f),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 20402 T2868 C163 P35483 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 20402 T2868 C163 P35483 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@629efc6a lockFactory=org.apache.lucene.store.NativeFSLockFactory@a70928f),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@629efc6a lockFactory=org.apache.lucene.store.NativeFSLockFactory@a70928f),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 20403 T2868 C163 P35483 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 20403 T2868 C163 P35483 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty1
[junit4:junit4]   2> 20404 T2868 C163 P35483 oass.SolrIndexSearcher.<init> Opening Searcher@b151529 realtime
[junit4:junit4]   2> 20404 T2868 C163 P35483 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 20405 T2868 C163 P35483 /update {waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 6
[junit4:junit4]   2> 20405 T2908 C162 P35495 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 20405 T2908 C162 P35495 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 20407 T2869 C163 P35483 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 20407 T2869 C163 P35483 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20408 T2908 C162 P35495 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 20408 T2908 C162 P35495 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 20408 T2908 C162 P35495 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 20410 T2869 C163 P35483 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty1
[junit4:junit4]   2> 20411 T2869 C163 P35483 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty1/index
[junit4:junit4]   2> 20411 T2869 C163 P35483 REQ /replication {command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20412 T2908 C162 P35495 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 20414 T2908 C162 P35495 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/index.20130301152952456 forceNew:false
[junit4:junit4]   2> 20414 T2908 C162 P35495 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3
[junit4:junit4]   2> 20414 T2908 C162 P35495 oash.SnapPuller.fetchLatestIndex Starting download to BaseDirectoryWrapper(org.apache.lucene.store.MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/index4037240390tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@6bd910c6) fullCopy=true
[junit4:junit4]   2> 20417 T2869 C163 P35483 REQ /replication {file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
[junit4:junit4]   2> 20418 T2908 C162 P35495 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/index
[junit4:junit4]   2> 20419 T2908 C162 P35495 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 20419 T2908 C162 P35495 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130301152952456
[junit4:junit4]   2> 20420 T2908 C162 P35495 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3
[junit4:junit4]   2> 20421 T2908 C162 P35495 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3
[junit4:junit4]   2> 20421 T2908 C162 P35495 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/index/ new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/index.20130301152952456
[junit4:junit4]   2> 20424 T2908 C162 P35495 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/index4037240390tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@6bd910c6),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 20425 T2908 C162 P35495 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 20425 T2908 C162 P35495 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3
[junit4:junit4]   2> 20426 T2908 C162 P35495 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3
[junit4:junit4]   2> 20426 T2908 C162 P35495 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 20427 T2908 C162 P35495 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 20427 T2908 C162 P35495 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 20427 T2908 C162 P35495 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/index.20130301152952456
[junit4:junit4]   2> 20428 T2908 C162 P35495 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3
[junit4:junit4]   2> 20431 T2908 C162 P35495 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/index4037240390tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@6bd910c6),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 20431 T2908 C162 P35495 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 20431 T2908 C162 P35495 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 20432 T2908 C162 P35495 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3
[junit4:junit4]   2> 20432 T2908 C162 P35495 oass.SolrIndexSearcher.<init> Opening Searcher@163cb1bc main
[junit4:junit4]   2> 20433 T2907 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@163cb1bc main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 20434 T2907 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/index
[junit4:junit4]   2> 20434 T2908 C162 P35495 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/index.20130301152952456
[junit4:junit4]   2> 20434 T2908 C162 P35495 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/index
[junit4:junit4]   2> 20434 T2908 C162 P35495 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 20435 T2908 C162 P35495 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 20435 T2908 C162 P35495 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 20435 T2908 C162 P35495 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 20436 T2908 C162 P35495 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 20663 T2857 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20664 T2857 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:35483_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:35483"}
[junit4:junit4]   2> 20667 T2857 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:35495_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:35495"}
[junit4:junit4]   2> 20679 T2856 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> 20679 T2890 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> 20679 T2862 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> 20679 T2905 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> 20679 T2875 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> 21195 T2834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 21196 T2834 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4]   2> 21196 T2834 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C164 name=onenodecollectioncore org.apache.solr.core.SolrCore@1b05d1a5 url=http://127.0.0.1:35483/onenodecollectioncore node=127.0.0.1:35483_ C164_STATE=coll:onenodecollection core:onenodecollectioncore props:{shard=shard1, roles=none, state=active, core=onenodecollectioncore, collection=onenodecollection, node_name=127.0.0.1:35483_, base_url=http://127.0.0.1:35483, leader=true}
[junit4:junit4]   2> 21222 T2870 C164 P35483 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362144572050/onenodecollection
[junit4:junit4]   2> 21225 T2870 C164 P35483 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5575b2b5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5cd5fcdc),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 21225 T2870 C164 P35483 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 21227 T2870 C164 P35483 /update {wt=javabin&version=2} {add=[1 (1428312129028489216)]} 0 5
[junit4:junit4]   2> 21233 T2870 C164 P35483 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 21235 T2870 C164 P35483 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5575b2b5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5cd5fcdc),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5575b2b5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5cd5fcdc),segFN=segments_2,generation=2,filenames=[_0.fnm, _0.dvd, _0.nvm, _0.dvm, _0.pos, _0.nvd, _0.tim, segments_2, _0.fdx, _0.si, _0.tip, _0.doc, _0.fdt]
[junit4:junit4]   2> 21235 T2870 C164 P35483 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_0.fnm, _0.dvd, _0.nvm, _0.dvm, _0.pos, _0.nvd, _0.tim, segments_2, _0.fdx, _0.si, _0.tip, _0.doc, _0.fdt]
[junit4:junit4]   2> 21236 T2870 C164 P35483 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362144572050/onenodecollection
[junit4:junit4]   2> 21237 T2870 C164 P35483 oass.SolrIndexSearcher.<init> Opening Searcher@a3506ff main
[junit4:junit4]   2> 21237 T2870 C164 P35483 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 21238 T2909 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@a3506ff main{StandardDirectoryReader(segments_2:3 _0(5.0):C1)}
[junit4:junit4]   2> 21238 T2909 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362144572050/onenodecollection/index
[junit4:junit4]   2> 21239 T2870 C164 P35483 /update {waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 6
[junit4:junit4]   2> 21242 T2870 C164 P35483 REQ /select {q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 21243 T2834 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 21251 T2870 C164 P35483 REQ /select {q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> ASYNC  NEW_CORE C165 name=collection1 org.apache.solr.core.SolrCore@5153efc9 url=http://127.0.0.1:35476/collection1 node=127.0.0.1:35476_ C165_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:35476_, base_url=http://127.0.0.1:35476, leader=true}
[junit4:junit4]   2> 21258 T2846 C165 P35476 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/control/data
[junit4:junit4]   2> 21259 T2846 C165 P35476 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5b63f50b lockFactory=org.apache.lucene.store.NativeFSLockFactory@41d5a12f),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 21260 T2846 C165 P35476 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 21262 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[1 (1428312129065189376)]} 0 5
[junit4:junit4]   2>  C162_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:35495_, base_url=http://127.0.0.1:35495}
[junit4:junit4]   2> 21283 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1428312129083015168)]} 0 2
[junit4:junit4]   2> 21284 T2871 C163 P35483 /update {distrib.from=http://127.0.0.1:35489/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[1 (1428312129083015168)]} 0 10
[junit4:junit4]   2> ASYNC  NEW_CORE C166 name=collection1 org.apache.solr.core.SolrCore@1120c600 url=http://127.0.0.1:35489/collection1 node=127.0.0.1:35489_ C166_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:35489_, base_url=http://127.0.0.1:35489, leader=true}
[junit4:junit4]   2> 21284 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[1]} 0 12
[junit4:junit4]   2> 21287 T2846 C165 P35476 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 21290 T2846 C165 P35476 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5b63f50b lockFactory=org.apache.lucene.store.NativeFSLockFactory@41d5a12f),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5b63f50b lockFactory=org.apache.lucene.store.NativeFSLockFactory@41d5a12f),segFN=segments_2,generation=2,filenames=[_0.fnm, _0.dvd, _0.nvm, _0.dvm, _0.pos, _0.nvd, _0.tim, segments_2, _0.fdx, _0.si, _0.tip, _0.doc, _0.fdt]
[junit4:junit4]   2> 21291 T2846 C165 P35476 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_0.fnm, _0.dvd, _0.nvm, _0.dvm, _0.pos, _0.nvd, _0.tim, segments_2, _0.fdx, _0.si, _0.tip, _0.doc, _0.fdt]
[junit4:junit4]   2> 21291 T2846 C165 P35476 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/control/data
[junit4:junit4]   2> 21343 T2846 C165 P35476 oass.SolrIndexSearcher.<init> Opening Searcher@4afa9dec main
[junit4:junit4]   2> 21344 T2846 C165 P35476 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 21344 T2860 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4afa9dec main{StandardDirectoryReader(segments_2:3 _0(5.0):C1)}
[junit4:junit4]   2> 21344 T2860 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/control/data/index
[junit4:junit4]   2> 21345 T2846 C165 P35476 /update {waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 58
[junit4:junit4]   2> 21347 T2882 C166 P35489 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 21348 T2882 C166 P35489 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty2
[junit4:junit4]   2> 21349 T2882 C166 P35489 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@12f7296e lockFactory=org.apache.lucene.store.NativeFSLockFactory@5e838fb0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 21350 T2882 C166 P35489 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 21350 T2882 C166 P35489 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@12f7296e lockFactory=org.apache.lucene.store.NativeFSLockFactory@5e838fb0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@12f7296e lockFactory=org.apache.lucene.store.NativeFSLockFactory@5e838fb0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 21351 T2882 C166 P35489 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 21351 T2882 C166 P35489 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty2
[junit4:junit4]   2> 21351 T2882 C166 P35489 oass.SolrIndexSearcher.<init> Opening Searcher@1f7bbeea main
[junit4:junit4]   2> 21352 T2882 C166 P35489 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 21352 T2892 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1f7bbeea main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 21353 T2892 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty2/index
[junit4:junit4]   2> 21353 T2882 C166 P35489 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:35483/collection1/, StdNode: http://127.0.0.1:35495/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4]   2> 21355 T2896 C162 P35495 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 21356 T2871 C163 P35483 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 21359 T2871 C163 P35483 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@629efc6a lockFactory=org.apache.lucene.store.NativeFSLockFactory@a70928f),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@629efc6a lockFactory=org.apache.lucene.store.NativeFSLockFactory@a70928f),segFN=segments_3,generation=3,filenames=[_0.fnm, _0.dvd, _0.nvm, _0.dvm, _0.pos, _0.nvd, _0.tim, _0.fdx, _0.si, _0.tip, _0.doc, segments_3, _0.fdt]
[junit4:junit4]   2> 21360 T2871 C163 P35483 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0.fnm, _0.dvd, _0.nvm, _0.dvm, _0.pos, _0.nvd, _0.tim, _0.fdx, _0.si, _0.tip, _0.doc, segments_3, _0.fdt]
[junit4:junit4]   2> 21360 T2871 C163 P35483 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty1
[junit4:junit4]   2> 21361 T2871 C163 P35483 oass.SolrIndexSearcher.<init> Opening Searcher@e4aee6 main
[junit4:junit4]   2> 21361 T2871 C163 P35483 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty1/index
[junit4:junit4]   2> 21362 T2871 C163 P35483 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 21362 T2877 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e4aee6 main{StandardDirectoryReader(segments_3:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 21362 T2877 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty1/index
[junit4:junit4]   2> 21363 T2871 C163 P35483 /update {waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 7
[junit4:junit4]   2> 21364 T1492 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 21414 T2896 C162 P35495 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/index4037240390tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@6bd910c6),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/index4037240390tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@6bd910c6),segFN=segments_3,generation=3,filenames=[_0.fnm, _0.dvd, _0.nvm, _0.dvm, _0.pos, _0.nvd, _0.tim, _0.fdx, _0.si, _0.tip, _0.doc, segments_3, _0.fdt]
[junit4:junit4]   2> 21414 T2896 C162 P35495 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0.fnm, _0.dvd, _0.nvm, _0.dvm, _0.pos, _0.nvd, _0.tim, _0.fdx, _0.si, _0.tip, _0.doc, segments_3, _0.fdt]
[junit4:junit4]   2> 21415 T2896 C162 P35495 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3
[junit4:junit4]   2> 21418 T2896 C162 P35495 oass.SolrIndexSearcher.<init> Opening Searcher@68027887 main
[junit4:junit4]   2> 21419 T2896 C162 P35495 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 21419 T2907 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@68027887 main{StandardDirectoryReader(segments_3:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 21419 T2907 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/index.20130301152952456
[junit4:junit4]   2> 21419 T2896 C162 P35495 /update {waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 64
[junit4:junit4]   2> 21420 T2882 C166 P35489 /update {waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 73
[junit4:junit4]   2> 21420 T2834 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):230
[junit4:junit4]   2> 21421 T2834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 21422 T2834 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4]   2> 21424 T2846 C165 P35476 REQ /select {q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 21425 T2834 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35473/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@7a371c69
[junit4:junit4]   2> 21426 T2834 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 21426 T2916 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:35473. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 21426 T2916 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35473, initiating session
[junit4:junit4]   2> 21427 T2836 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:35522
[junit4:junit4]   2> 21427 T2836 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:35522
[junit4:junit4]   2> 21428 T2838 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d2624b298000b with negotiated timeout 10000 for client /140.211.11.196:35522
[junit4:junit4]   2> 21428 T2916 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:35473, sessionid = 0x13d2624b298000b, negotiated timeout = 10000
[junit4:junit4]   2> 21428 T2917 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a371c69 name:ZooKeeperConnection Watcher:127.0.0.1:35473/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 21428 T2834 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 21429 T2834 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 21431 T2839 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d2624b298000b
[junit4:junit4]   2> 21432 T2836 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:35522 which had sessionid 0x13d2624b298000b
[junit4:junit4]   2> 21432 T2917 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 21432 T2834 oaz.ZooKeeper.close Session: 0x13d2624b298000b closed
[junit4:junit4]   2> 21433 T2865 C163 P35483 REQ /select {q=*:*&distrib=false&wt=javabin&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 21434 T2883 C166 P35489 REQ /select {q=*:*&distrib=false&wt=javabin&version=2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 21438 T2884 C166 P35489 REQ /select {NOW=1362144593479&shard.url=127.0.0.1:35489/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> 21438 T2920 C163 P35483 REQ /select {NOW=1362144593479&shard.url=127.0.0.1:35483/collection1/|127.0.0.1:35495/collection1/&fl=id,score&start=0&q=*:*&distrib=false&wt=javabin&isShard=true&fsv=true&version=2&rows=10} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 21441 T2920 C163 P35483 REQ /select {NOW=1362144593479&shard.url=127.0.0.1:35483/collection1/|127.0.0.1:35495/collection1/&ids=1&q=*:*&distrib=false&wt=javabin&isShard=true&version=2} status=0 QTime=0 
[junit4:junit4]   2> 21442 T2868 C163 P35483 REQ /select {q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=7 
[junit4:junit4]   2> 21446 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[2 (1428312129261273088)]} 0 2
[junit4:junit4]   2> 21451 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[2 (1428312129266515968)]} 0 2
[junit4:junit4]   2> 21454 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[3 (1428312129270710272)]} 0 1
[junit4:junit4]   2> 21458 T2885 C166 P35489 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[3 (1428312129274904576)]} 0 1
[junit4:junit4]   2> 21459 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[3]} 0 3
[junit4:junit4]   2> 21462 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[4 (1428312129279098880)]} 0 1
[junit4:junit4]   2> 21471 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[4 (1428312129282244608)]} 0 3
[junit4:junit4]   2> 21471 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[4 (1428312129282244608)]} 0 7
[junit4:junit4]   2> 21475 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[5 (1428312129292730368)]} 0 1
[junit4:junit4]   2> 21480 T2885 C166 P35489 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[5 (1428312129297973248)]} 0 1
[junit4:junit4]   2> 21480 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[5]} 0 3
[junit4:junit4]   2> 21482 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[6 (1428312129301118976)]} 0 0
[junit4:junit4]   2> 21487 T2885 C166 P35489 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[6 (1428312129306361856)]} 0 0
[junit4:junit4]   2> 21488 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[6]} 0 3
[junit4:junit4]   2> 21490 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[7 (1428312129309507584)]} 0 0
[junit4:junit4]   2> 21494 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[7 (1428312129312653312)]} 0 1
[junit4:junit4]   2> 21497 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[8 (1428312129315799040)]} 0 1
[junit4:junit4]   2> 21505 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[8 (1428312129321041920)]} 0 1
[junit4:junit4]   2> 21505 T2871 C163 P35483 /update {distrib.from=http://127.0.0.1:35489/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[8 (1428312129321041920)]} 0 4
[junit4:junit4]   2> 21505 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[8]} 0 6
[junit4:junit4]   2> 21508 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[9 (1428312129328381952)]} 0 0
[junit4:junit4]   2> 21511 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[9 (1428312129331527680)]} 0 0
[junit4:junit4]   2> 21514 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[10 (1428312129334673408)]} 0 0
[junit4:junit4]   2> 21520 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10 (1428312129337819136)]} 0 0
[junit4:junit4]   2> 21521 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[10 (1428312129337819136)]} 0 4
[junit4:junit4]   2> 21524 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[11 (1428312129344110592)]} 0 1
[junit4:junit4]   2> 21530 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[11 (1428312129347256320)]} 0 1
[junit4:junit4]   2> 21530 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[11 (1428312129347256320)]} 0 4
[junit4:junit4]   2> 21532 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[12 (1428312129353547776)]} 0 0
[junit4:junit4]   2> 21540 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[12 (1428312129358790656)]} 0 0
[junit4:junit4]   2> 21541 T2871 C163 P35483 /update {distrib.from=http://127.0.0.1:35489/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[12 (1428312129358790656)]} 0 4
[junit4:junit4]   2> 21541 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[12]} 0 6
[junit4:junit4]   2> 21544 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[13 (1428312129366130688)]} 0 0
[junit4:junit4]   2> 21550 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[13 (1428312129369276416)]} 0 0
[junit4:junit4]   2> 21551 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[13 (1428312129369276416)]} 0 4
[junit4:junit4]   2> 21553 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[14 (1428312129375567872)]} 0 0
[junit4:junit4]   2> 21559 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[14 (1428312129378713600)]} 0 0
[junit4:junit4]   2> 21560 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[14 (1428312129378713600)]} 0 4
[junit4:junit4]   2> 21562 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[15 (1428312129385005056)]} 0 0
[junit4:junit4]   2> 21571 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[15 (1428312129390247936)]} 0 1
[junit4:junit4]   2> 21571 T2871 C163 P35483 /update {distrib.from=http://127.0.0.1:35489/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[15 (1428312129390247936)]} 0 4
[junit4:junit4]   2> 21572 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[15]} 0 7
[junit4:junit4]   2> 21574 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[16 (1428312129397587968)]} 0 0
[junit4:junit4]   2> 21583 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[16 (1428312129402830848)]} 0 1
[junit4:junit4]   2> 21583 T2871 C163 P35483 /update {distrib.from=http://127.0.0.1:35489/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[16 (1428312129402830848)]} 0 4
[junit4:junit4]   2> 21583 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[16]} 0 6
[junit4:junit4]   2> 21587 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[17 (1428312129410170880)]} 0 1
[junit4:junit4]   2> 21591 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[17 (1428312129414365184)]} 0 1
[junit4:junit4]   2> 21594 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[100 (1428312129418559488)]} 0 0
[junit4:junit4]   2> 21602 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[100 (1428312129423802368)]} 0 0
[junit4:junit4]   2> 21603 T2871 C163 P35483 /update {distrib.from=http://127.0.0.1:35489/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[100 (1428312129423802368)]} 0 4
[junit4:junit4]   2> 21603 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[100]} 0 6
[junit4:junit4]   2> 21607 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[101 (1428312129431142400)]} 0 1
[junit4:junit4]   2> 21614 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[101 (1428312129436385280)]} 0 0
[junit4:junit4]   2> 21615 T2871 C163 P35483 /update {distrib.from=http://127.0.0.1:35489/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[101 (1428312129436385280)]} 0 4
[junit4:junit4]   2> 21615 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[101]} 0 6
[junit4:junit4]   2> 21619 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[102 (1428312129443725312)]} 0 1
[junit4:junit4]   2> 21624 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[102 (1428312129446871040)]} 0 0
[junit4:junit4]   2> 21625 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[102 (1428312129446871040)]} 0 4
[junit4:junit4]   2> 21628 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[103 (1428312129453162496)]} 0 1
[junit4:junit4]   2> 21633 T2885 C166 P35489 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[103 (1428312129458405376)]} 0 1
[junit4:junit4]   2> 21633 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[103]} 0 3
[junit4:junit4]   2> 21637 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[104 (1428312129462599680)]} 0 1
[junit4:junit4]   2> 21642 T2885 C166 P35489 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[104 (1428312129467842560)]} 0 1
[junit4:junit4]   2> 21642 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[104]} 0 3
[junit4:junit4]   2> 21646 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[105 (1428312129472036864)]} 0 1
[junit4:junit4]   2> 21651 T2885 C166 P35489 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[105 (1428312129477279744)]} 0 1
[junit4:junit4]   2> 21651 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[105]} 0 3
[junit4:junit4]   2> 21655 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[106 (1428312129481474048)]} 0 1
[junit4:junit4]   2> 21658 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[106 (1428312129484619776)]} 0 1
[junit4:junit4]   2> 21661 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[107 (1428312129487765504)]} 0 1
[junit4:junit4]   2> 21668 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[107 (1428312129493008384)]} 0 0
[junit4:junit4]   2> 21669 T2871 C163 P35483 /update {distrib.from=http://127.0.0.1:35489/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[107 (1428312129493008384)]} 0 4
[junit4:junit4]   2> 21669 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[107]} 0 6
[junit4:junit4]   2> 21673 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[108 (1428312129500348416)]} 0 1
[junit4:junit4]   2> 21680 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[108 (1428312129505591296)]} 0 0
[junit4:junit4]   2> 21681 T2871 C163 P35483 /update {distrib.from=http://127.0.0.1:35489/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[108 (1428312129505591296)]} 0 4
[junit4:junit4]   2> 21681 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[108]} 0 6
[junit4:junit4]   2> 21685 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[109 (1428312129512931328)]} 0 1
[junit4:junit4]   2> 21690 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[109 (1428312129516077056)]} 0 0
[junit4:junit4]   2> 21691 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[109 (1428312129516077056)]} 0 4
[junit4:junit4]   2> 21694 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[110 (1428312129522368512)]} 0 1
[junit4:junit4]   2> 21700 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[110 (1428312129527611392)]} 0 0
[junit4:junit4]   2> 21701 T2871 C163 P35483 /update {distrib.from=http://127.0.0.1:35489/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[110 (1428312129527611392)]} 0 3
[junit4:junit4]   2> 21701 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[110]} 0 5
[junit4:junit4]   2> 21704 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[111 (1428312129533902848)]} 0 0
[junit4:junit4]   2> 21713 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[111 (1428312129539145728)]} 0 1
[junit4:junit4]   2> 21713 T2871 C163 P35483 /update {distrib.from=http://127.0.0.1:35489/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[111 (1428312129539145728)]} 0 4
[junit4:junit4]   2> 21713 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[111]} 0 6
[junit4:junit4]   2> 21717 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[112 (1428312129546485760)]} 0 1
[junit4:junit4]   2> 21722 T2885 C166 P35489 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[112 (1428312129551728640)]} 0 1
[junit4:junit4]   2> 21722 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[112]} 0 3
[junit4:junit4]   2> 21726 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[113 (1428312129555922944)]} 0 1
[junit4:junit4]   2> 21733 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[113 (1428312129561165824)]} 0 0
[junit4:junit4]   2> 21734 T2871 C163 P35483 /update {distrib.from=http://127.0.0.1:35489/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[113 (1428312129561165824)]} 0 4
[junit4:junit4]   2> 21734 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[113]} 0 6
[junit4:junit4]   2> 21737 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[114 (1428312129568505856)]} 0 0
[junit4:junit4]   2> 21743 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[114 (1428312129571651584)]} 0 0
[junit4:junit4]   2> 21744 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[114 (1428312129571651584)]} 0 4
[junit4:junit4]   2> 21746 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[115 (1428312129577943040)]} 0 0
[junit4:junit4]   2> 21751 T2885 C166 P35489 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[115 (1428312129583185920)]} 0 0
[junit4:junit4]   2> 21752 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[115]} 0 3
[junit4:junit4]   2> 21754 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[116 (1428312129586331648)]} 0 0
[junit4:junit4]   2> 21758 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[116 (1428312129589477376)]} 0 1
[junit4:junit4]   2> 21760 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[117 (1428312129592623104)]} 0 0
[junit4:junit4]   2> 21764 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[117 (1428312129595768832)]} 0 1
[junit4:junit4]   2> 21766 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[118 (1428312129598914560)]} 0 0
[junit4:junit4]   2> 21771 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[118 (1428312129602060288)]} 0 0
[junit4:junit4]   2> 21772 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[118 (1428312129602060288)]} 0 3
[junit4:junit4]   2> 21774 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[119 (1428312129607303168)]} 0 0
[junit4:junit4]   2> 21779 T2885 C166 P35489 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[119 (1428312129612546048)]} 0 0
[junit4:junit4]   2> 21780 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[119]} 0 3
[junit4:junit4]   2> 21782 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[120 (1428312129615691776)]} 0 0
[junit4:junit4]   2> 21786 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[120 (1428312129618837504)]} 0 1
[junit4:junit4]   2> 21788 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[121 (1428312129621983232)]} 0 0
[junit4:junit4]   2> 21792 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[121 (1428312129625128960)]} 0 1
[junit4:junit4]   2> 21794 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[122 (1428312129628274688)]} 0 0
[junit4:junit4]   2> 21802 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[122 (1428312129633517568)]} 0 0
[junit4:junit4]   2> 21803 T2871 C163 P35483 /update {distrib.from=http://127.0.0.1:35489/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[122 (1428312129633517568)]} 0 4
[junit4:junit4]   2> 21803 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[122]} 0 6
[junit4:junit4]   2> 21806 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[123 (1428312129640857600)]} 0 0
[junit4:junit4]   2> 21811 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[123 (1428312129644003328)]} 0 0
[junit4:junit4]   2> 21812 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[123 (1428312129644003328)]} 0 3
[junit4:junit4]   2> 21814 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[124 (1428312129649246208)]} 0 0
[junit4:junit4]   2> 21821 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[124 (1428312129654489088)]} 0 0
[junit4:junit4]   2> 21822 T2871 C163 P35483 /update {distrib.from=http://127.0.0.1:35489/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[124 (1428312129654489088)]} 0 3
[junit4:junit4]   2> 21822 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[124]} 0 5
[junit4:junit4]   2> 21825 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[125 (1428312129660780544)]} 0 0
[junit4:junit4]   2> 21831 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[125 (1428312129663926272)]} 0 0
[junit4:junit4]   2> 21832 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[125 (1428312129663926272)]} 0 4
[junit4:junit4]   2> 21834 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[126 (1428312129670217728)]} 0 0
[junit4:junit4]   2> 21838 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[126 (1428312129673363456)]} 0 1
[junit4:junit4]   2> 21840 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[127 (1428312129676509184)]} 0 0
[junit4:junit4]   2> 21846 T2885 C166 P35489 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[127 (1428312129681752064)]} 0 1
[junit4:junit4]   2> 21846 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[127]} 0 3
[junit4:junit4]   2> 21849 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[128 (1428312129685946368)]} 0 0
[junit4:junit4]   2> 21854 T2885 C166 P35489 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[128 (1428312129691189248)]} 0 0
[junit4:junit4]   2> 21855 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[128]} 0 3
[junit4:junit4]   2> 21857 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[129 (1428312129694334976)]} 0 0
[junit4:junit4]   2> 21862 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[129 (1428312129697480704)]} 0 0
[junit4:junit4]   2> 21863 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[129 (1428312129697480704)]} 0 3
[junit4:junit4]   2> 21865 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[130 (1428312129702723584)]} 0 0
[junit4:junit4]   2> 21870 T2885 C166 P35489 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[130 (1428312129707966464)]} 0 0
[junit4:junit4]   2> 21871 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[130]} 0 3
[junit4:junit4]   2> 21873 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[131 (1428312129711112192)]} 0 0
[junit4:junit4]   2> 21877 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[131 (1428312129714257920)]} 0 1
[junit4:junit4]   2> 21879 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[132 (1428312129717403648)]} 0 0
[junit4:junit4]   2> 21887 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[132 (1428312129722646528)]} 0 0
[junit4:junit4]   2> 21888 T2871 C163 P35483 /update {distrib.from=http://127.0.0.1:35489/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[132 (1428312129722646528)]} 0 4
[junit4:junit4]   2> 21888 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[132]} 0 6
[junit4:junit4]   2> 21891 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[133 (1428312129729986560)]} 0 0
[junit4:junit4]   2> 21896 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[133 (1428312129733132288)]} 0 0
[junit4:junit4]   2> 21897 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[133 (1428312129733132288)]} 0 3
[junit4:junit4]   2> 21899 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[134 (1428312129738375168)]} 0 0
[junit4:junit4]   2> 21903 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[134 (1428312129741520896)]} 0 1
[junit4:junit4]   2> 21905 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[135 (1428312129744666624)]} 0 0
[junit4:junit4]   2> 21910 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[135 (1428312129747812352)]} 0 0
[junit4:junit4]   2> 21911 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[135 (1428312129747812352)]} 0 3
[junit4:junit4]   2> 21913 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[136 (1428312129753055232)]} 0 0
[junit4:junit4]   2> 21917 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[136 (1428312129756200960)]} 0 1
[junit4:junit4]   2> 21919 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[137 (1428312129759346688)]} 0 0
[junit4:junit4]   2> 21923 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[137 (1428312129762492416)]} 0 1
[junit4:junit4]   2> 21925 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[138 (1428312129765638144)]} 0 0
[junit4:junit4]   2> 21932 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[138 (1428312129770881024)]} 0 0
[junit4:junit4]   2> 21933 T2871 C163 P35483 /update {distrib.from=http://127.0.0.1:35489/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[138 (1428312129770881024)]} 0 3
[junit4:junit4]   2> 21933 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[138]} 0 5
[junit4:junit4]   2> 21936 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[139 (1428312129777172480)]} 0 0
[junit4:junit4]   2> 21941 T2885 C166 P35489 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[139 (1428312129782415360)]} 0 0
[junit4:junit4]   2> 21942 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[139]} 0 3
[junit4:junit4]   2> 21944 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[140 (1428312129785561088)]} 0 0
[junit4:junit4]   2> 21949 T2885 C166 P35489 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[140 (1428312129790803968)]} 0 0
[junit4:junit4]   2> 21950 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[140]} 0 3
[junit4:junit4]   2> 21952 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[141 (1428312129793949696)]} 0 0
[junit4:junit4]   2> 21956 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[141 (1428312129797095424)]} 0 1
[junit4:junit4]   2> 21958 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[142 (1428312129800241152)]} 0 0
[junit4:junit4]   2> 21963 T2885 C166 P35489 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[142 (1428312129805484032)]} 0 0
[junit4:junit4]   2> 21964 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[142]} 0 3
[junit4:junit4]   2> 21966 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[143 (1428312129808629760)]} 0 0
[junit4:junit4]   2> 21970 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[143 (1428312129811775488)]} 0 1
[junit4:junit4]   2> 21972 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[144 (1428312129814921216)]} 0 0
[junit4:junit4]   2> 21976 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[144 (1428312129818066944)]} 0 1
[junit4:junit4]   2> 21978 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[145 (1428312129821212672)]} 0 0
[junit4:junit4]   2> 21982 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[145 (1428312129824358400)]} 0 1
[junit4:junit4]   2> 21984 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[146 (1428312129827504128)]} 0 0
[junit4:junit4]   2> 21992 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[146 (1428312129832747008)]} 0 0
[junit4:junit4]   2> 21993 T2871 C163 P35483 /update {distrib.from=http://127.0.0.1:35489/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[146 (1428312129832747008)]} 0 4
[junit4:junit4]   2> 21993 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[146]} 0 6
[junit4:junit4]   2> 21996 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[147 (1428312129840087040)]} 0 0
[junit4:junit4]   2> 22001 T2885 C166 P35489 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[147 (1428312129845329920)]} 0 0
[junit4:junit4]   2> 22002 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[147]} 0 3
[junit4:junit4]   2> 22004 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[148 (1428312129848475648)]} 0 0
[junit4:junit4]   2> 22010 T2895 C162 P35495 /update {distrib.from=http://127.0.0.1:35483/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[148 (1428312129851621376)]} 0 0
[junit4:junit4]   2> 22011 T2868 C163 P35483 /update {wt=javabin&version=2} {add=[148 (1428312129851621376)]} 0 4
[junit4:junit4]   2> 22013 T2846 C165 P35476 /update {wt=javabin&version=2} {add=[149 (1428312129857912832)]} 0 0
[junit4:junit4]   2> 22017 T2882 C166 P35489 /update {wt=javabin&version=2} {add=[149 (1428312129861058560)]} 0 1
[junit4:junit4]   2> 22017 T2834 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):230
[junit4:junit4]   2> 22018 T2834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22019 T2834 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4]   2> 22021 T2846 C165 P35476 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 22043 T2846 C165 P35476 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5b63f50b lockFactory=org.apache.lucene.store.NativeFSLockFactory@41d5a12f),segFN=segments_2,generation=2,filenames=[_0.fnm, _0.dvd, _0.nvm, _0.dvm, _0.pos, _0.nvd, _0.tim, segments_2, _0.fdx, _0.si, _0.tip, _0.doc, _0.fdt]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5b63f50b lockFactory

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

pache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/index.20130301152952456
[junit4:junit4]   2> 87108 T2905 oash.SnapPuller$2.preClose removing old index files MockDirWrapper(org.apache.lucene.store.RAMDirectory@57ee1ab0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@13e3ed98)
[junit4:junit4]   2> 87108 T2905 oasc.CachingDirectoryFactory.closeDirectory Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/index.20130301152952456
[junit4:junit4]   2> 87221 T2905 oash.SnapPuller$2.postClose removing old index directory MockDirWrapper(org.apache.lucene.store.RAMDirectory@57ee1ab0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@13e3ed98)
[junit4:junit4]   2> 87221 T2905 oasc.CachingDirectoryFactory.close Closing directory when closing factory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/index
[junit4:junit4]   2> 87221 T2905 oasc.CachingDirectoryFactory.closeDirectory Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3/index
[junit4:junit4]   2> 87222 T2905 oasc.CachingDirectoryFactory.close Closing directory when closing factory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3
[junit4:junit4]   2> 87222 T2905 oasc.CachingDirectoryFactory.closeDirectory Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362144572049/jetty3
[junit4:junit4]   2> 87223 T2905 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 87223 T2905 oasc.LeaderElector$1.process WARNING  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election/89269506674262026-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> 87224 T2905 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> 87224 T2905 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 87224 T2905 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 87224 T2905 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> 87225 T2905 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 87225 T2905 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> 87225 T2905 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=sk_SK, timezone=Egypt
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=3,free=283416200,total=351666176
[junit4:junit4]   2> NOTE: All tests run in this JVM: [FileUtilsTest, TestArbitraryIndexDir, SliceStateTest, TestSolrDeletionPolicy1, TestMergePolicyConfig, BasicFunctionalityTest, TestSolrCoreProperties, PrimitiveFieldTypeTest, TestZkChroot, SynonymTokenizerTest, TestCodecSupport, SchemaVersionSpecificBehaviorTest, ShardRoutingTest, TestSort, TestComponentsName, TestQueryUtils, RAMDirectoryFactoryTest, ReturnFieldsTest, TestDocumentBuilder, HardAutoCommitTest, RecoveryZkTest, LukeRequestHandlerTest, FullSolrCloudDistribCmdsTest, DistributedQueryElevationComponentTest, TestUpdate, TestSolrXMLSerializer, LegacyHTMLStripCharFilterTest, DocValuesTest, TestPhraseSuggestions, OpenExchangeRatesOrgProviderTest, UpdateParamsTest, TestReversedWildcardFilterFactory, TestElisionMultitermQuery, TestSolrJ, CollectionsAPIDistributedZkTest, TestLRUCache, PolyFieldTest, URLClassifyProcessorTest, TestCharFilters, TestRemoteStreaming, TestDistributedGrouping, TestDFRSimilarityFactory, SuggesterTSTTest, SolrIndexSplitterTest, TestAtomicUpdateErrorCases, DebugComponentTest, TestOmitPositions, QueryEqualityTest, SuggesterTest, SliceStateUpdateTest, BasicZkTest, PrimUtilsTest, SpellingQueryConverterTest, TestCSVResponseWriter, TestDocSet, StatsComponentTest, TestMultiCoreConfBootstrap, TestBinaryField, TestCSVLoader, DirectSolrSpellCheckerTest, ZkNodePropsTest, ConvertedLegacyTest, OverseerTest, SpellCheckComponentTest, TestReplicationHandler, LeaderElectionTest, TestRealTimeGet, ZkControllerTest, TestDistributedSearch, TestHashPartitioner, TestJoin, FastVectorHighlighterTest, SearchHandlerTest, UniqFieldsUpdateProcessorFactoryTest, CSVRequestHandlerTest, ShowFileRequestHandlerTest, NotRequiredUniqueKeyTest, TestFoldingMultitermQuery, TestLuceneMatchVersion, UpdateRequestProcessorFactoryTest, TestWriterPerf, FieldMutatingUpdateProcessorTest, HighlighterConfigTest, TestPropInjectDefaults, TestQuerySenderListener, SolrIndexConfigTest, NumericFieldsTest, TestNumberUtils, MultiTermTest, TestBM25SimilarityFactory, TestIBSimilarityFactory, TestFastLRUCache, TestSystemIdResolver, DOMUtilTest, UUIDFieldTest, TestUtils, ChaosMonkeyNothingIsSafeTest, PreAnalyzedFieldTest, CircularListTest, AnalysisAfterCoreReloadTest, PathHierarchyTokenizerFactoryTest, BasicDistributedZk2Test]
[junit4:junit4] Completed on J1 in 87.79s, 1 test, 1 error <<< FAILURES!

[...truncated 94 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/build.xml:381: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/build.xml:361: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build.xml:183: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/lucene/common-build.xml:1207: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/lucene/common-build.xml:870: There were test failures: 257 suites, 1075 tests, 1 error, 22 ignored (4 assumptions)

Total time: 46 minutes 22 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message