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-java7 - Build # 3775 - Failure
Date Fri, 01 Mar 2013 17:03:54 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-java7/3775/

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([36380598939CF0CE:B7DE8B80E4C390F2]:0)
	at org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:430)
	at org.apache.solr.cloud.BasicDistributedZk2Test.brindDownShardIndexSomeDocsAndRecover(BasicDistributedZk2Test.java:295)
	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:116)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:722)




Build Log:
[...truncated 9530 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 0 T4068 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /ddr/o
[junit4:junit4]   2> 4 T4068 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362157158654
[junit4:junit4]   2> 6 T4068 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 6 T4069 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 9 T4069 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 9 T4069 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4]   2> 9 T4069 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4]   2> 10 T4069 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 11 T4069 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4]   2> 107 T4068 oasc.ZkTestServer.run start zk server on port:13278
[junit4:junit4]   2> 107 T4068 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13278 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@53f9b2b2
[junit4:junit4]   2> 108 T4068 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 109 T4074 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13278. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 109 T4074 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13278, initiating session
[junit4:junit4]   2> 109 T4070 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:13279
[junit4:junit4]   2> 110 T4070 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:13279
[junit4:junit4]   2> 110 T4072 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 132 T4072 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d26e4c1040000 with negotiated timeout 10000 for client /140.211.11.196:13279
[junit4:junit4]   2> 132 T4074 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13278, sessionid = 0x13d26e4c1040000, negotiated timeout = 10000
[junit4:junit4]   2> 133 T4075 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@53f9b2b2 name:ZooKeeperConnection Watcher:127.0.0.1:13278 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 133 T4068 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 134 T4068 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 136 T4073 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d26e4c1040000
[junit4:junit4]   2> 154 T4075 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 155 T4070 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:13279 which had sessionid 0x13d26e4c1040000
[junit4:junit4]   2> 154 T4068 oaz.ZooKeeper.close Session: 0x13d26e4c1040000 closed
[junit4:junit4]   2> 155 T4068 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13278/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@6c4d3fa9
[junit4:junit4]   2> 156 T4068 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 156 T4076 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13278. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 157 T4076 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13278, initiating session
[junit4:junit4]   2> 157 T4070 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:13280
[junit4:junit4]   2> 157 T4070 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:13280
[junit4:junit4]   2> 159 T4072 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d26e4c1040001 with negotiated timeout 10000 for client /140.211.11.196:13280
[junit4:junit4]   2> 159 T4076 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13278, sessionid = 0x13d26e4c1040001, negotiated timeout = 10000
[junit4:junit4]   2> 159 T4077 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6c4d3fa9 name:ZooKeeperConnection Watcher:127.0.0.1:13278/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 159 T4068 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 160 T4068 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 189 T4068 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 197 T4068 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 223 T4068 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 225 T4068 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 226 T4068 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 278 T4068 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 279 T4068 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 394 T4068 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 395 T4068 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 415 T4068 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 416 T4068 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 419 T4068 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 419 T4068 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 455 T4068 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 456 T4068 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 464 T4068 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 465 T4068 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 468 T4068 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 468 T4068 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 487 T4068 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 488 T4068 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 490 T4073 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d26e4c1040001
[junit4:junit4]   2> 492 T4077 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 492 T4070 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:13280 which had sessionid 0x13d26e4c1040001
[junit4:junit4]   2> 492 T4068 oaz.ZooKeeper.close Session: 0x13d26e4c1040001 closed
[junit4:junit4]   2> 657 T4068 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 662 T4068 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:13281
[junit4:junit4]   2> 663 T4068 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 664 T4068 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 664 T4068 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362157159141
[junit4:junit4]   2> 665 T4068 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362157159141/solr.xml
[junit4:junit4]   2> 665 T4068 oasc.CoreContainer.<init> New CoreContainer 1208871678
[junit4:junit4]   2> 666 T4068 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362157159141/'
[junit4:junit4]   2> 667 T4068 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362157159141/'
[junit4:junit4]   2> 728 T4068 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 729 T4068 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 730 T4068 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 730 T4068 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 731 T4068 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 731 T4068 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 732 T4068 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 732 T4068 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 733 T4068 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 733 T4068 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 757 T4068 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 777 T4068 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:13278/solr
[junit4:junit4]   2> 777 T4068 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 778 T4068 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13278 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@53b8424c
[junit4:junit4]   2> 779 T4087 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13278. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 779 T4068 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 780 T4087 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13278, initiating session
[junit4:junit4]   2> 780 T4070 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:13282
[junit4:junit4]   2> 781 T4070 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:13282
[junit4:junit4]   2> 787 T4072 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d26e4c1040002 with negotiated timeout 20000 for client /140.211.11.196:13282
[junit4:junit4]   2> 787 T4087 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13278, sessionid = 0x13d26e4c1040002, negotiated timeout = 20000
[junit4:junit4]   2> 788 T4088 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@53b8424c name:ZooKeeperConnection Watcher:127.0.0.1:13278 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 788 T4068 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 789 T4073 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d26e4c1040002
[junit4:junit4]   2> 799 T4088 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 799 T4070 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:13282 which had sessionid 0x13d26e4c1040002
[junit4:junit4]   2> 799 T4068 oaz.ZooKeeper.close Session: 0x13d26e4c1040002 closed
[junit4:junit4]   2> 800 T4068 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 813 T4068 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13278/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@2a65b564
[junit4:junit4]   2> 814 T4089 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13278. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 814 T4068 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 815 T4089 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13278, initiating session
[junit4:junit4]   2> 815 T4070 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:13283
[junit4:junit4]   2> 815 T4070 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:13283
[junit4:junit4]   2> 816 T4072 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d26e4c1040003 with negotiated timeout 20000 for client /140.211.11.196:13283
[junit4:junit4]   2> 816 T4089 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13278, sessionid = 0x13d26e4c1040003, negotiated timeout = 20000
[junit4:junit4]   2> 817 T4090 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a65b564 name:ZooKeeperConnection Watcher:127.0.0.1:13278/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 817 T4068 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 823 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 825 T4068 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 832 T4068 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:13281_ddr%2Fo
[junit4:junit4]   2> 832 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:13281_ddr%2Fo Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:13281_ddr%2Fo
[junit4:junit4]   2> 833 T4068 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:13281_ddr%2Fo
[junit4:junit4]   2> 836 T4068 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 851 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040003 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> 852 T4068 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 860 T4068 oasc.Overseer.start Overseer (id=89270331549941763-127.0.0.1:13281_ddr%2Fo-n_0000000000) starting
[junit4:junit4]   2> 861 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 862 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 868 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 869 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 870 T4092 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 871 T4068 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 883 T4068 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 885 T4091 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 890 T4093 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362157159141/collection1
[junit4:junit4]   2> 890 T4093 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 891 T4093 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 891 T4093 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 892 T4093 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362157159141/collection1/'
[junit4:junit4]   2> 893 T4093 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362157159141/collection1/lib/README' to classloader
[junit4:junit4]   2> 893 T4093 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362157159141/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 929 T4093 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 970 T4093 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 1071 T4093 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 1078 T4093 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1711 T4093 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1721 T4093 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1725 T4093 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1736 T4093 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1740 T4093 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1744 T4093 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1745 T4093 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1746 T4093 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362157159141/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/control/data/
[junit4:junit4]   2> 1747 T4093 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@79f64d29
[junit4:junit4]   2> 1747 T4093 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 1748 T4093 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/control/data forceNew:false
[junit4:junit4]   2> 1748 T4093 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/control/data
[junit4:junit4]   2> 1748 T4093 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/control/data/index/
[junit4:junit4]   2> 1749 T4093 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1750 T4093 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/control/data/index forceNew:false
[junit4:junit4]   2> 1752 T4093 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e84dec2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c5e04e1),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1753 T4093 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 1754 T4093 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/control/data/index
[junit4:junit4]   2> 1756 T4093 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1756 T4093 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1756 T4093 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1757 T4093 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1757 T4093 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1758 T4093 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1758 T4093 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1759 T4093 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1759 T4093 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1771 T4093 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1776 T4093 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/control/data
[junit4:junit4]   2> 1776 T4093 oass.SolrIndexSearcher.<init> Opening Searcher@2f7a6f84 main
[junit4:junit4]   2> 1777 T4093 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/control/data/tlog
[junit4:junit4]   2> 1778 T4093 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1778 T4093 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1781 T4094 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2f7a6f84 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1782 T4093 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 1783 T4093 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1783 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040003 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> 2388 T4091 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2389 T4091 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":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:13281_ddr%2Fo",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:13281/ddr/o"}
[junit4:junit4]   2> 2389 T4091 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 2389 T4091 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 2390 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040003 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> 2438 T4090 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> 2825 T4093 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 2825 T4093 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:13281/ddr/o collection:control_collection shard:shard1
[junit4:junit4]   2> 2826 T4093 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 2844 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040003 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> 2844 T4093 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 2845 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040003 type:create cxid:0x73 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2855 T4093 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2856 T4093 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2856 T4093 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:13281/ddr/o/collection1/
[junit4:junit4]   2> 2856 T4093 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 2856 T4093 oasc.SyncStrategy.syncToMe http://127.0.0.1:13281/ddr/o/collection1/ has no replicas
[junit4:junit4]   2> 2857 T4093 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:13281/ddr/o/collection1/
[junit4:junit4]   2> 2857 T4093 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 2860 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040003 type:create cxid:0x7d zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3949 T4091 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3969 T4090 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> 3992 T4093 oasc.ZkController.register We are http://127.0.0.1:13281/ddr/o/collection1/ and leader is http://127.0.0.1:13281/ddr/o/collection1/
[junit4:junit4]   2> 3992 T4093 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:13281/ddr/o
[junit4:junit4]   2> 3992 T4093 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 3992 T4093 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 3993 T4093 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 3994 T4093 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3995 T4068 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 3996 T4068 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 3996 T4068 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 4011 T4068 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 4013 T4068 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13278/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@65342e5f
[junit4:junit4]   2> 4014 T4068 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4014 T4095 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13278. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 4015 T4095 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13278, initiating session
[junit4:junit4]   2> 4015 T4070 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:13284
[junit4:junit4]   2> 4015 T4070 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:13284
[junit4:junit4]   2> 4016 T4072 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d26e4c1040004 with negotiated timeout 10000 for client /140.211.11.196:13284
[junit4:junit4]   2> 4016 T4095 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13278, sessionid = 0x13d26e4c1040004, negotiated timeout = 10000
[junit4:junit4]   2> 4017 T4096 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@65342e5f name:ZooKeeperConnection Watcher:127.0.0.1:13278/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4017 T4068 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4018 T4068 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4019 T4068 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 4223 T4068 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 4225 T4068 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:13285
[junit4:junit4]   2> 4226 T4068 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 4227 T4068 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4227 T4068 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362157162669
[junit4:junit4]   2> 4228 T4068 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362157162669/solr.xml
[junit4:junit4]   2> 4228 T4068 oasc.CoreContainer.<init> New CoreContainer 1555046647
[junit4:junit4]   2> 4229 T4068 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362157162669/'
[junit4:junit4]   2> 4230 T4068 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362157162669/'
[junit4:junit4]   2> 4304 T4068 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 4305 T4068 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 4306 T4068 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 4306 T4068 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 4307 T4068 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 4307 T4068 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 4308 T4068 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 4308 T4068 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 4309 T4068 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 4309 T4068 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 4333 T4068 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 4355 T4068 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:13278/solr
[junit4:junit4]   2> 4356 T4068 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 4356 T4068 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13278 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@2fbc462a
[junit4:junit4]   2> 4357 T4068 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4358 T4106 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13278. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 4358 T4106 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13278, initiating session
[junit4:junit4]   2> 4359 T4070 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:13286
[junit4:junit4]   2> 4359 T4070 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:13286
[junit4:junit4]   2> 4361 T4072 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d26e4c1040005 with negotiated timeout 20000 for client /140.211.11.196:13286
[junit4:junit4]   2> 4361 T4106 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13278, sessionid = 0x13d26e4c1040005, negotiated timeout = 20000
[junit4:junit4]   2> 4362 T4107 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2fbc462a name:ZooKeeperConnection Watcher:127.0.0.1:13278 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4362 T4068 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4363 T4073 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d26e4c1040005
[junit4:junit4]   2> 4377 T4107 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 4377 T4070 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:13286 which had sessionid 0x13d26e4c1040005
[junit4:junit4]   2> 4377 T4068 oaz.ZooKeeper.close Session: 0x13d26e4c1040005 closed
[junit4:junit4]   2> 4378 T4068 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 4389 T4068 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13278/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@723ff6b1
[junit4:junit4]   2> 4390 T4108 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13278. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 4390 T4068 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4391 T4108 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13278, initiating session
[junit4:junit4]   2> 4391 T4070 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:13287
[junit4:junit4]   2> 4391 T4070 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:13287
[junit4:junit4]   2> 4393 T4072 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d26e4c1040006 with negotiated timeout 20000 for client /140.211.11.196:13287
[junit4:junit4]   2> 4393 T4108 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13278, sessionid = 0x13d26e4c1040006, negotiated timeout = 20000
[junit4:junit4]   2> 4393 T4109 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@723ff6b1 name:ZooKeeperConnection Watcher:127.0.0.1:13278/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4393 T4068 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4394 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040006 type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4396 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040006 type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4397 T4068 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 5400 T4068 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:13285_ddr%2Fo
[junit4:junit4]   2> 5401 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040006 type:delete cxid:0x9 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:13285_ddr%2Fo Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:13285_ddr%2Fo
[junit4:junit4]   2> 5404 T4068 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:13285_ddr%2Fo
[junit4:junit4]   2> 5421 T4090 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> 5421 T4109 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5421 T4096 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5424 T4090 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5429 T4110 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362157162669/collection1
[junit4:junit4]   2> 5429 T4110 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 5430 T4110 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 5430 T4110 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 5431 T4110 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362157162669/collection1/'
[junit4:junit4]   2> 5433 T4110 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362157162669/collection1/lib/README' to classloader
[junit4:junit4]   2> 5433 T4110 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362157162669/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 5474 T4091 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5475 T4091 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":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:13281_ddr%2Fo",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:13281/ddr/o"}
[junit4:junit4]   2> 5490 T4109 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> 5490 T4090 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> 5490 T4096 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> 5491 T4110 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 5559 T4110 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 5660 T4110 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 5667 T4110 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 6203 T4110 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 6210 T4110 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 6213 T4110 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 6223 T4110 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6227 T4110 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6230 T4110 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6230 T4110 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6231 T4110 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362157162669/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty1/
[junit4:junit4]   2> 6232 T4110 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@79f64d29
[junit4:junit4]   2> 6232 T4110 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 6233 T4110 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty1 forceNew:false
[junit4:junit4]   2> 6233 T4110 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty1
[junit4:junit4]   2> 6233 T4110 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty1/index/
[junit4:junit4]   2> 6234 T4110 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 6234 T4110 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty1/index forceNew:false
[junit4:junit4]   2> 6236 T4110 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6684277a lockFactory=org.apache.lucene.store.NativeFSLockFactory@20d2e6f0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 6236 T4110 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 6237 T4110 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty1/index
[junit4:junit4]   2> 6239 T4110 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 6239 T4110 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 6239 T4110 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 6240 T4110 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 6240 T4110 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 6240 T4110 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 6241 T4110 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 6241 T4110 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 6241 T4110 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 6256 T4110 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 6261 T4110 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty1
[junit4:junit4]   2> 6261 T4110 oass.SolrIndexSearcher.<init> Opening Searcher@77e5c9d1 main
[junit4:junit4]   2> 6262 T4110 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty1/tlog
[junit4:junit4]   2> 6263 T4110 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 6263 T4110 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 6267 T4111 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@77e5c9d1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 6268 T4110 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 6268 T4110 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 6994 T4091 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6995 T4091 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[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:13285_ddr%2Fo",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:13285/ddr/o"}
[junit4:junit4]   2> 6995 T4091 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4]   2> 6995 T4091 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 7036 T4090 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> 7036 T4109 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> 7036 T4096 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> 7271 T4110 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 7271 T4110 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:13285/ddr/o collection:collection1 shard:shard1
[junit4:junit4]   2> 7272 T4110 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 7303 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040006 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> 7311 T4110 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 7312 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040006 type:create cxid:0x47 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7321 T4110 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 7321 T4110 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 7322 T4110 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:13285/ddr/o/collection1/
[junit4:junit4]   2> 7322 T4110 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 7322 T4110 oasc.SyncStrategy.syncToMe http://127.0.0.1:13285/ddr/o/collection1/ has no replicas
[junit4:junit4]   2> 7322 T4110 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:13285/ddr/o/collection1/
[junit4:junit4]   2> 7323 T4110 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 7337 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040006 type:create cxid:0x51 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8540 T4091 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8557 T4109 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> 8557 T4096 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> 8557 T4090 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> 8571 T4110 oasc.ZkController.register We are http://127.0.0.1:13285/ddr/o/collection1/ and leader is http://127.0.0.1:13285/ddr/o/collection1/
[junit4:junit4]   2> 8571 T4110 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:13285/ddr/o
[junit4:junit4]   2> 8571 T4110 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 8571 T4110 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 8572 T4110 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 8573 T4110 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8574 T4068 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 8575 T4068 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 8575 T4068 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 8786 T4068 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 8789 T4068 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:13288
[junit4:junit4]   2> 8789 T4068 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 8790 T4068 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8790 T4068 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362157167242
[junit4:junit4]   2> 8791 T4068 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362157167242/solr.xml
[junit4:junit4]   2> 8791 T4068 oasc.CoreContainer.<init> New CoreContainer 1901806363
[junit4:junit4]   2> 8792 T4068 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362157167242/'
[junit4:junit4]   2> 8793 T4068 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362157167242/'
[junit4:junit4]   2> 8859 T4068 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 8859 T4068 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 8860 T4068 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 8860 T4068 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 8861 T4068 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 8861 T4068 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 8862 T4068 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 8862 T4068 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 8863 T4068 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 8863 T4068 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 8887 T4068 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 8908 T4068 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:13278/solr
[junit4:junit4]   2> 8910 T4068 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 8910 T4068 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13278 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@5388d25
[junit4:junit4]   2> 8912 T4068 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8913 T4121 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13278. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 8914 T4121 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13278, initiating session
[junit4:junit4]   2> 8914 T4070 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:13289
[junit4:junit4]   2> 8914 T4070 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:13289
[junit4:junit4]   2> 8916 T4072 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d26e4c1040007 with negotiated timeout 20000 for client /140.211.11.196:13289
[junit4:junit4]   2> 8916 T4121 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13278, sessionid = 0x13d26e4c1040007, negotiated timeout = 20000
[junit4:junit4]   2> 8917 T4122 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5388d25 name:ZooKeeperConnection Watcher:127.0.0.1:13278 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8917 T4068 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8918 T4073 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d26e4c1040007
[junit4:junit4]   2> 8925 T4122 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 8925 T4070 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:13289 which had sessionid 0x13d26e4c1040007
[junit4:junit4]   2> 8925 T4068 oaz.ZooKeeper.close Session: 0x13d26e4c1040007 closed
[junit4:junit4]   2> 8926 T4068 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 8939 T4068 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13278/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@17cc4bfb
[junit4:junit4]   2> 8940 T4068 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8940 T4123 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13278. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 8941 T4123 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13278, initiating session
[junit4:junit4]   2> 8941 T4070 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:13290
[junit4:junit4]   2> 8941 T4070 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:13290
[junit4:junit4]   2> 8943 T4072 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d26e4c1040008 with negotiated timeout 20000 for client /140.211.11.196:13290
[junit4:junit4]   2> 8943 T4123 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13278, sessionid = 0x13d26e4c1040008, negotiated timeout = 20000
[junit4:junit4]   2> 8943 T4124 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17cc4bfb name:ZooKeeperConnection Watcher:127.0.0.1:13278/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8943 T4068 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8944 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040008 type:create cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8946 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040008 type:create cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8954 T4068 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9957 T4068 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:13288_ddr%2Fo
[junit4:junit4]   2> 9958 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040008 type:delete cxid:0x9 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:13288_ddr%2Fo Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:13288_ddr%2Fo
[junit4:junit4]   2> 9960 T4068 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:13288_ddr%2Fo
[junit4:junit4]   2> 9962 T4090 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> 9963 T4096 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9963 T4124 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9963 T4096 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> 9963 T4109 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9963 T4109 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> 9964 T4090 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9981 T4125 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362157167242/collection1
[junit4:junit4]   2> 9981 T4125 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 9982 T4125 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 9982 T4125 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 9984 T4125 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362157167242/collection1/'
[junit4:junit4]   2> 9985 T4125 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362157167242/collection1/lib/README' to classloader
[junit4:junit4]   2> 9985 T4125 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362157167242/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 10037 T4125 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 10073 T4091 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10074 T4091 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[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:13285_ddr%2Fo",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:13285/ddr/o"}
[junit4:junit4]   2> 10087 T4109 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> 10087 T4090 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> 10087 T4096 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> 10087 T4124 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> 10103 T4125 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 10204 T4125 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 10211 T4125 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 10866 T4125 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 10878 T4125 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 10882 T4125 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 10897 T4125 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10902 T4125 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10906 T4125 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10907 T4125 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10909 T4125 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362157167242/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty2/
[junit4:junit4]   2> 10909 T4125 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@79f64d29
[junit4:junit4]   2> 10910 T4125 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 10911 T4125 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty2 forceNew:false
[junit4:junit4]   2> 10912 T4125 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty2
[junit4:junit4]   2> 10912 T4125 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty2/index/
[junit4:junit4]   2> 10913 T4125 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 10913 T4125 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty2/index forceNew:false
[junit4:junit4]   2> 10916 T4125 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@296cff80 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4bf27cbe),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10916 T4125 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 10917 T4125 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty2/index
[junit4:junit4]   2> 10919 T4125 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 10919 T4125 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 10920 T4125 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 10921 T4125 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 10921 T4125 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 10922 T4125 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 10922 T4125 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 10923 T4125 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 10923 T4125 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 10936 T4125 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 10941 T4125 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty2
[junit4:junit4]   2> 10942 T4125 oass.SolrIndexSearcher.<init> Opening Searcher@25b8534a main
[junit4:junit4]   2> 10942 T4125 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty2/tlog
[junit4:junit4]   2> 10943 T4125 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 10944 T4125 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 10948 T4126 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@25b8534a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 10950 T4125 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 10950 T4125 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 11591 T4091 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11592 T4091 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[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:13288_ddr%2Fo",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:13288/ddr/o"}
[junit4:junit4]   2> 11592 T4091 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 11593 T4091 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4]   2> 11639 T4124 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> 11639 T4090 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> 11639 T4096 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> 11639 T4109 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> 11954 T4125 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 11954 T4125 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:13288/ddr/o collection:collection1 shard:shard2
[junit4:junit4]   2> 11955 T4125 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 11973 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040008 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> 11975 T4125 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 11975 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040008 type:create cxid:0x46 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 11985 T4125 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 11985 T4125 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 11986 T4125 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:13288/ddr/o/collection1/
[junit4:junit4]   2> 11986 T4125 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 11986 T4125 oasc.SyncStrategy.syncToMe http://127.0.0.1:13288/ddr/o/collection1/ has no replicas
[junit4:junit4]   2> 11986 T4125 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:13288/ddr/o/collection1/
[junit4:junit4]   2> 11987 T4125 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 11990 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040008 type:create cxid:0x4f zxid:0x82 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 13143 T4091 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13166 T4124 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> 13166 T4109 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> 13166 T4090 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> 13166 T4096 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> 13171 T4125 oasc.ZkController.register We are http://127.0.0.1:13288/ddr/o/collection1/ and leader is http://127.0.0.1:13288/ddr/o/collection1/
[junit4:junit4]   2> 13171 T4125 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:13288/ddr/o
[junit4:junit4]   2> 13172 T4125 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 13172 T4125 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 13172 T4125 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 13178 T4125 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13179 T4068 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 13180 T4068 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 13180 T4068 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 13398 T4068 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 13401 T4068 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:13291
[junit4:junit4]   2> 13402 T4068 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 13402 T4068 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 13403 T4068 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362157171847
[junit4:junit4]   2> 13403 T4068 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362157171847/solr.xml
[junit4:junit4]   2> 13404 T4068 oasc.CoreContainer.<init> New CoreContainer 56750672
[junit4:junit4]   2> 13405 T4068 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362157171847/'
[junit4:junit4]   2> 13405 T4068 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362157171847/'
[junit4:junit4]   2> 13471 T4068 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 13472 T4068 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 13472 T4068 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 13473 T4068 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 13473 T4068 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 13474 T4068 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 13474 T4068 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 13475 T4068 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 13475 T4068 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 13476 T4068 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 13500 T4068 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 13521 T4068 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:13278/solr
[junit4:junit4]   2> 13521 T4068 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 13522 T4068 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13278 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@2a20e0e0
[junit4:junit4]   2> 13523 T4068 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 13524 T4136 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13278. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 13524 T4136 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13278, initiating session
[junit4:junit4]   2> 13525 T4070 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:13292
[junit4:junit4]   2> 13525 T4070 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:13292
[junit4:junit4]   2> 13527 T4072 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d26e4c1040009 with negotiated timeout 20000 for client /140.211.11.196:13292
[junit4:junit4]   2> 13527 T4136 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13278, sessionid = 0x13d26e4c1040009, negotiated timeout = 20000
[junit4:junit4]   2> 13528 T4137 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a20e0e0 name:ZooKeeperConnection Watcher:127.0.0.1:13278 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 13528 T4068 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 13529 T4073 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d26e4c1040009
[junit4:junit4]   2> 13530 T4137 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 13530 T4070 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:13292 which had sessionid 0x13d26e4c1040009
[junit4:junit4]   2> 13530 T4068 oaz.ZooKeeper.close Session: 0x13d26e4c1040009 closed
[junit4:junit4]   2> 13531 T4068 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 13544 T4068 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13278/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@647affb
[junit4:junit4]   2> 13545 T4068 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 13545 T4138 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13278. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 13546 T4138 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13278, initiating session
[junit4:junit4]   2> 13546 T4070 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:13293
[junit4:junit4]   2> 13547 T4070 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:13293
[junit4:junit4]   2> 13551 T4072 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d26e4c104000a with negotiated timeout 20000 for client /140.211.11.196:13293
[junit4:junit4]   2> 13551 T4138 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13278, sessionid = 0x13d26e4c104000a, negotiated timeout = 20000
[junit4:junit4]   2> 13551 T4139 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@647affb name:ZooKeeperConnection Watcher:127.0.0.1:13278/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 13552 T4068 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 13552 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c104000a type:create cxid:0x1 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 13554 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c104000a type:create cxid:0x2 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 13556 T4068 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 14558 T4068 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:13291_ddr%2Fo
[junit4:junit4]   2> 14559 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c104000a type:delete cxid:0x9 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:13291_ddr%2Fo Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:13291_ddr%2Fo
[junit4:junit4]   2> 14561 T4068 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:13291_ddr%2Fo
[junit4:junit4]   2> 14564 T4090 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> 14564 T4109 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14564 T4139 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14564 T4109 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> 14564 T4096 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14564 T4124 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14565 T4096 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> 14565 T4124 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> 14571 T4090 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14578 T4140 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362157171847/collection1
[junit4:junit4]   2> 14578 T4140 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 14579 T4140 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 14579 T4140 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 14580 T4140 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362157171847/collection1/'
[junit4:junit4]   2> 14581 T4140 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362157171847/collection1/lib/README' to classloader
[junit4:junit4]   2> 14582 T4140 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362157171847/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 14634 T4140 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 14679 T4091 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14680 T4091 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[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:13288_ddr%2Fo",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:13288/ddr/o"}
[junit4:junit4]   2> 14707 T4124 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> 14707 T4090 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> 14707 T4109 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> 14707 T4096 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> 14707 T4139 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> 14717 T4140 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 14817 T4140 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 14824 T4140 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 15425 T4140 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 15436 T4140 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 15439 T4140 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 15451 T4140 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 15456 T4140 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 15460 T4140 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 15462 T4140 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 15463 T4140 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362157171847/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3/
[junit4:junit4]   2> 15463 T4140 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@79f64d29
[junit4:junit4]   2> 15463 T4140 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 15464 T4140 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3 forceNew:false
[junit4:junit4]   2> 15465 T4140 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3
[junit4:junit4]   2> 15465 T4140 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3/index/
[junit4:junit4]   2> 15465 T4140 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 15466 T4140 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3/index forceNew:false
[junit4:junit4]   2> 15468 T4140 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7fe6014f lockFactory=org.apache.lucene.store.NativeFSLockFactory@1caff0f8),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 15469 T4140 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 15470 T4140 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3/index
[junit4:junit4]   2> 15472 T4140 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 15472 T4140 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 15473 T4140 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 15473 T4140 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 15474 T4140 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 15474 T4140 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 15474 T4140 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 15475 T4140 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 15475 T4140 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 15487 T4140 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 15493 T4140 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3
[junit4:junit4]   2> 15493 T4140 oass.SolrIndexSearcher.<init> Opening Searcher@c76bffd main
[junit4:junit4]   2> 15494 T4140 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3/tlog
[junit4:junit4]   2> 15495 T4140 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 15495 T4140 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 15500 T4141 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c76bffd main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 15502 T4140 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 15503 T4140 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 16212 T4091 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16213 T4091 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[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:13291_ddr%2Fo",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:13291/ddr/o"}
[junit4:junit4]   2> 16213 T4091 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 16213 T4091 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 16257 T4090 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> 16257 T4096 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> 16258 T4109 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> 16257 T4139 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> 16257 T4124 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> 16512 T4140 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 16512 T4140 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:13291/ddr/o collection:collection1 shard:shard1
[junit4:junit4]   2> 16515 T4140 oasc.ZkController.register We are http://127.0.0.1:13291/ddr/o/collection1/ and leader is http://127.0.0.1:13285/ddr/o/collection1/
[junit4:junit4]   2> 16515 T4140 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:13291/ddr/o
[junit4:junit4]   2> 16515 T4140 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 16515 T4140 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C301 name=collection1 org.apache.solr.core.SolrCore@4a1f7523 url=http://127.0.0.1:13291/ddr/o/collection1 node=127.0.0.1:13291_ddr%2Fo C301_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:13291_ddr%2Fo, base_url=http://127.0.0.1:13291/ddr/o}
[junit4:junit4]   2> 16517 T4142 C301 P13291 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 16517 T4142 C301 P13291 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 16517 T4140 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16517 T4142 C301 P13291 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 16517 T4142 C301 P13291 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 16518 T4068 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 16518 T4142 C301 P13291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 16519 T4068 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 16519 T4068 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 16534 T4068 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16535 T4068 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 16548 T4100 oasc.CoreContainer.create Creating SolrCore 'onenodecollectioncore' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362157162669/onenodecollectioncore
[junit4:junit4]   2> 16548 T4100 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4]   2> 16549 T4100 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4]   2> 16549 T4100 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4]   2> 16550 T4100 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4]   2> 16550 T4100 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4]   2> 16552 T4100 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4]   2> 16553 T4100 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362157162669/onenodecollectioncore/'
[junit4:junit4]   2> 16622 T4100 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 16664 T4100 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 16765 T4100 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 16770 T4100 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 17197 T4100 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 17204 T4100 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 17224 T4100 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 17234 T4100 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 17237 T4100 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 17241 T4100 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 17242 T4100 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 17242 T4100 oasc.SolrCore.<init> [onenodecollectioncore] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362157162669/onenodecollectioncore/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362157158654/onenodecollection/
[junit4:junit4]   2> 17243 T4100 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@79f64d29
[junit4:junit4]   2> 17243 T4100 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 17244 T4100 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362157158654/onenodecollection forceNew:false
[junit4:junit4]   2> 17244 T4100 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362157158654/onenodecollection
[junit4:junit4]   2> 17245 T4100 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362157158654/onenodecollection/index/
[junit4:junit4]   2> 17245 T4100 oasc.SolrCore.initIndex WARNING [onenodecollectioncore] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362157158654/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 17246 T4100 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362157158654/onenodecollection/index forceNew:false
[junit4:junit4]   2> 17248 T4100 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@16a9c311 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6f33a3a4),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 17248 T4100 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 17249 T4100 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362157158654/onenodecollection/index
[junit4:junit4]   2> 17250 T4100 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 17251 T4100 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 17251 T4100 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 17252 T4100 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 17252 T4100 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 17252 T4100 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 17253 T4100 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 17253 T4100 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 17254 T4100 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 17262 T4100 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 17266 T4100 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362157158654/onenodecollection
[junit4:junit4]   2> 17267 T4100 oass.SolrIndexSearcher.<init> Opening Searcher@8554199 main
[junit4:junit4]   2> 17267 T4100 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362157158654/onenodecollection/tlog
[junit4:junit4]   2> 17268 T4100 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 17268 T4100 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 17270 T4143 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@8554199 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 17272 T4100 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4]   2> 17761 T4091 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 17762 T4091 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[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:13291_ddr%2Fo",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:13291/ddr/o"}
[junit4:junit4]   2> 17765 T4091 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:13285_ddr%2Fo",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:13285/ddr/o"}
[junit4:junit4]   2> 17765 T4091 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4]   2> 17766 T4091 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 17777 T4090 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> 17777 T4139 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> 17777 T4096 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> 17777 T4124 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> 17777 T4109 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> 18296 T4100 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4]   2> 18296 T4100 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:13285/ddr/o collection:onenodecollection shard:shard1
[junit4:junit4]   2> 18297 T4100 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4]   2> 18315 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040006 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> 18316 T4100 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 18316 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040006 type:create cxid:0xa0 zxid:0xad txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 18324 T4100 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 18325 T4100 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 18325 T4100 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:13285/ddr/o/onenodecollectioncore/
[junit4:junit4]   2> 18325 T4100 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 18326 T4100 oasc.SyncStrategy.syncToMe http://127.0.0.1:13285/ddr/o/onenodecollectioncore/ has no replicas
[junit4:junit4]   2> 18326 T4100 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:13285/ddr/o/onenodecollectioncore/
[junit4:junit4]   2> 18327 T4100 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4]   2> 18330 T4073 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d26e4c1040006 type:create cxid:0xaa zxid:0xb1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 19288 T4091 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19311 T4090 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> 19311 T4096 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> 19311 T4109 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> 19311 T4139 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> 19311 T4124 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> 19351 T4100 oasc.ZkController.register We are http://127.0.0.1:13285/ddr/o/onenodecollectioncore/ and leader is http://127.0.0.1:13285/ddr/o/onenodecollectioncore/
[junit4:junit4]   2> 19351 T4100 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:13285/ddr/o
[junit4:junit4]   2> 19351 T4100 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 19352 T4100 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4]   2> 19354 T4100 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19355 T4068 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4]   2> 19356 T4068 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20358 T4068 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C301_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:13291_ddr%2Fo, base_url=http://127.0.0.1:13291/ddr/o}
[junit4:junit4]   2> 20536 T4142 C301 P13291 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:13285/ddr/o/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 20536 T4142 C301 P13291 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:13291/ddr/o START replicas=[http://127.0.0.1:13285/ddr/o/collection1/] nUpdates=100
[junit4:junit4]   2> 20536 T4142 C301 P13291 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 20537 T4142 C301 P13291 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 20537 T4142 C301 P13291 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 20537 T4142 C301 P13291 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 20537 T4142 C301 P13291 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 20537 T4142 C301 P13291 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:13285/ddr/o/collection1/. core=collection1
[junit4:junit4]   2> 20537 T4142 C301 P13291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C302 name=collection1 org.apache.solr.core.SolrCore@59206f20 url=http://127.0.0.1:13285/ddr/o/collection1 node=127.0.0.1:13285_ddr%2Fo C302_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:13285_ddr%2Fo, base_url=http://127.0.0.1:13285/ddr/o, leader=true}
[junit4:junit4]   2> 20542 T4101 C302 P13285 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0 
[junit4:junit4]   2> 20549 T4102 C302 P13285 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 20550 T4102 C302 P13285 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty1
[junit4:junit4]   2> 20552 T4102 C302 P13285 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6684277a lockFactory=org.apache.lucene.store.NativeFSLockFactory@20d2e6f0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 20552 T4102 C302 P13285 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 20553 T4102 C302 P13285 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6684277a lockFactory=org.apache.lucene.store.NativeFSLockFactory@20d2e6f0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6684277a lockFactory=org.apache.lucene.store.NativeFSLockFactory@20d2e6f0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 20553 T4102 C302 P13285 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 20553 T4102 C302 P13285 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty1
[junit4:junit4]   2> 20554 T4102 C302 P13285 oass.SolrIndexSearcher.<init> Opening Searcher@31b33a realtime
[junit4:junit4]   2> 20554 T4102 C302 P13285 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 20555 T4102 C302 P13285 /update {waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 6
[junit4:junit4]   2> 20555 T4142 C301 P13291 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 20555 T4142 C301 P13291 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 20558 T4103 C302 P13285 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 20558 T4103 C302 P13285 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20559 T4142 C301 P13291 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 20559 T4142 C301 P13291 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 20559 T4142 C301 P13291 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 20561 T4103 C302 P13285 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty1
[junit4:junit4]   2> 20562 T4103 C302 P13285 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty1/index
[junit4:junit4]   2> 20562 T4103 C302 P13285 REQ /replication {command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20563 T4142 C301 P13291 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 20564 T4142 C301 P13291 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3/index.20130301125939212 forceNew:false
[junit4:junit4]   2> 20564 T4142 C301 P13291 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3
[junit4:junit4]   2> 20564 T4142 C301 P13291 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@3fa09ae5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1d1644c1) fullCopy=true
[junit4:junit4]   2> 20567 T4103 C302 P13285 REQ /replication {file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
[junit4:junit4]   2> 20568 T4142 C301 P13291 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3/index
[junit4:junit4]   2> 20568 T4142 C301 P13291 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 20569 T4142 C301 P13291 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130301125939212
[junit4:junit4]   2> 20569 T4142 C301 P13291 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3
[junit4:junit4]   2> 20569 T4142 C301 P13291 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3
[junit4:junit4]   2> 20570 T4142 C301 P13291 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3/index/ new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3/index.20130301125939212
[junit4:junit4]   2> 20571 T4142 C301 P13291 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3fa09ae5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1d1644c1),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 20571 T4142 C301 P13291 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 20571 T4142 C301 P13291 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3
[junit4:junit4]   2> 20572 T4142 C301 P13291 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3
[junit4:junit4]   2> 20572 T4142 C301 P13291 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 20572 T4142 C301 P13291 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 20572 T4142 C301 P13291 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 20572 T4142 C301 P13291 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3/index.20130301125939212
[junit4:junit4]   2> 20573 T4142 C301 P13291 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3
[junit4:junit4]   2> 20574 T4142 C301 P13291 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3fa09ae5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1d1644c1),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 20574 T4142 C301 P13291 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 20574 T4142 C301 P13291 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 20574 T4142 C301 P13291 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3
[junit4:junit4]   2> 20574 T4142 C301 P13291 oass.SolrIndexSearcher.<init> Opening Searcher@7ae7d2bd main
[junit4:junit4]   2> 20575 T4141 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7ae7d2bd main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 20576 T4141 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3/index
[junit4:junit4]   2> 20576 T4142 C301 P13291 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3/index.20130301125939212
[junit4:junit4]   2> 20577 T4142 C301 P13291 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3/index
[junit4:junit4]   2> 20577 T4142 C301 P13291 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 20577 T4142 C301 P13291 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 20577 T4142 C301 P13291 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 20577 T4142 C301 P13291 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 20584 T4142 C301 P13291 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 20819 T4091 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20820 T4091 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:13285_ddr%2Fo",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:13285/ddr/o"}
[junit4:junit4]   2> 20823 T4091 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[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:13291_ddr%2Fo",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:13291/ddr/o"}
[junit4:junit4]   2> 20838 T4090 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> 20838 T4124 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> 20838 T4096 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> 20838 T4109 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> 20838 T4139 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> 21360 T4068 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 21362 T4068 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4]   2> 21362 T4068 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C303 name=onenodecollectioncore org.apache.solr.core.SolrCore@694a7a50 url=http://127.0.0.1:13285/ddr/o/onenodecollectioncore node=127.0.0.1:13285_ddr%2Fo C303_STATE=coll:onenodecollection core:onenodecollectioncore props:{shard=shard1, roles=none, state=active, core=onenodecollectioncore, collection=onenodecollection, node_name=127.0.0.1:13285_ddr%2Fo, base_url=http://127.0.0.1:13285/ddr/o, leader=true}
[junit4:junit4]   2> 21397 T4104 C303 P13285 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362157158654/onenodecollection
[junit4:junit4]   2> 21399 T4104 C303 P13285 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@16a9c311 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6f33a3a4),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 21400 T4104 C303 P13285 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 21402 T4104 C303 P13285 /update {wt=javabin&version=2} {add=[1 (1428325327223914496)]} 0 6
[junit4:junit4]   2> 21410 T4104 C303 P13285 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 21414 T4104 C303 P13285 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@16a9c311 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6f33a3a4),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@16a9c311 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6f33a3a4),segFN=segments_2,generation=2,filenames=[_0_MockRandom_0.tib, _0.fnm, _0_TestBloomFilteredLucene41Postings_0.blm, _0_Lucene42_0.dvd, _0_TestBloomFilteredLucene41Postings_0.tim, _0_Memory_0.ram, _0_Lucene41_0.pos, _0_Lucene42_0.dvm, _0_TestBloomFilteredLucene41Postings_0.tip, _0.nvm, _0_TestBloomFilteredLucene41Postings_0.pos, _0_MockRandom_0.sd, _0_Lucene41_0.doc, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0.nvd, _0_MockRandom_0.tii, _0_TestBloomFilteredLucene41Postings_0.doc, segments_2, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip]
[junit4:junit4]   2> 21415 T4104 C303 P13285 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_0_MockRandom_0.tib, _0.fnm, _0_TestBloomFilteredLucene41Postings_0.blm, _0_Lucene42_0.dvd, _0_TestBloomFilteredLucene41Postings_0.tim, _0_Memory_0.ram, _0_Lucene41_0.pos, _0_Lucene42_0.dvm, _0_TestBloomFilteredLucene41Postings_0.tip, _0.nvm, _0_TestBloomFilteredLucene41Postings_0.pos, _0_MockRandom_0.sd, _0_Lucene41_0.doc, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0.nvd, _0_MockRandom_0.tii, _0_TestBloomFilteredLucene41Postings_0.doc, segments_2, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip]
[junit4:junit4]   2> 21415 T4104 C303 P13285 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362157158654/onenodecollection
[junit4:junit4]   2> 21417 T4104 C303 P13285 oass.SolrIndexSearcher.<init> Opening Searcher@2e729b44 main
[junit4:junit4]   2> 21418 T4104 C303 P13285 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 21418 T4143 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@2e729b44 main{StandardDirectoryReader(segments_2:3 _0(5.0):C1)}
[junit4:junit4]   2> 21419 T4143 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362157158654/onenodecollection/index
[junit4:junit4]   2> 21419 T4104 C303 P13285 /update {waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 9
[junit4:junit4]   2> 21423 T4104 C303 P13285 REQ /select {q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 21425 T4068 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 21439 T4104 C303 P13285 REQ /select {q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> ASYNC  NEW_CORE C304 name=collection1 org.apache.solr.core.SolrCore@34ce4462 url=http://127.0.0.1:13281/ddr/o/collection1 node=127.0.0.1:13281_ddr%2Fo C304_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:13281_ddr%2Fo, base_url=http://127.0.0.1:13281/ddr/o, leader=true}
[junit4:junit4]   2> 21448 T4080 C304 P13281 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/control/data
[junit4:junit4]   2> 21451 T4080 C304 P13281 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e84dec2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c5e04e1),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 21451 T4080 C304 P13281 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 21455 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[1 (1428325327277391872)]} 0 7
[junit4:junit4]   2>  C301_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:13291_ddr%2Fo, base_url=http://127.0.0.1:13291/ddr/o}
[junit4:junit4]   2> 21491 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1428325327305703424)]} 0 4
[junit4:junit4]   2> 21492 T4105 C302 P13285 /update {distrib.from=http://127.0.0.1:13288/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[1 (1428325327305703424)]} 0 17
[junit4:junit4]   2> ASYNC  NEW_CORE C305 name=collection1 org.apache.solr.core.SolrCore@4ccfdcb6 url=http://127.0.0.1:13288/ddr/o/collection1 node=127.0.0.1:13288_ddr%2Fo C305_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:13288_ddr%2Fo, base_url=http://127.0.0.1:13288/ddr/o, leader=true}
[junit4:junit4]   2> 21493 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[1]} 0 21
[junit4:junit4]   2> 21496 T4080 C304 P13281 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 21503 T4080 C304 P13281 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e84dec2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c5e04e1),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e84dec2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c5e04e1),segFN=segments_2,generation=2,filenames=[_0_MockRandom_0.tib, _0.fnm, _0_TestBloomFilteredLucene41Postings_0.blm, _0_Lucene42_0.dvd, _0_Lucene41_0.pos, _0_TestBloomFilteredLucene41Postings_0.tim, _0_Memory_0.ram, _0_Lucene42_0.dvm, _0_TestBloomFilteredLucene41Postings_0.tip, _0.nvm, _0_TestBloomFilteredLucene41Postings_0.pos, _0_MockRandom_0.sd, _0_Lucene41_0.doc, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0.nvd, _0_TestBloomFilteredLucene41Postings_0.doc, _0_MockRandom_0.tii, segments_2, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip]
[junit4:junit4]   2> 21503 T4080 C304 P13281 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_0_MockRandom_0.tib, _0.fnm, _0_TestBloomFilteredLucene41Postings_0.blm, _0_Lucene42_0.dvd, _0_Lucene41_0.pos, _0_TestBloomFilteredLucene41Postings_0.tim, _0_Memory_0.ram, _0_Lucene42_0.dvm, _0_TestBloomFilteredLucene41Postings_0.tip, _0.nvm, _0_TestBloomFilteredLucene41Postings_0.pos, _0_MockRandom_0.sd, _0_Lucene41_0.doc, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0.nvd, _0_TestBloomFilteredLucene41Postings_0.doc, _0_MockRandom_0.tii, segments_2, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip]
[junit4:junit4]   2> 21504 T4080 C304 P13281 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/control/data
[junit4:junit4]   2> 21506 T4080 C304 P13281 oass.SolrIndexSearcher.<init> Opening Searcher@40c69c7e main
[junit4:junit4]   2> 21507 T4080 C304 P13281 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 21507 T4094 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@40c69c7e main{StandardDirectoryReader(segments_2:3 _0(5.0):C1)}
[junit4:junit4]   2> 21508 T4094 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/control/data/index
[junit4:junit4]   2> 21508 T4080 C304 P13281 /update {waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 12
[junit4:junit4]   2> 21511 T4116 C305 P13288 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 21512 T4116 C305 P13288 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty2
[junit4:junit4]   2> 21514 T4116 C305 P13288 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@296cff80 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4bf27cbe),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 21514 T4116 C305 P13288 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 21515 T4116 C305 P13288 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@296cff80 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4bf27cbe),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@296cff80 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4bf27cbe),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 21516 T4116 C305 P13288 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 21516 T4116 C305 P13288 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty2
[junit4:junit4]   2> 21517 T4116 C305 P13288 oass.SolrIndexSearcher.<init> Opening Searcher@2572b009 main
[junit4:junit4]   2> 21517 T4116 C305 P13288 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 21518 T4126 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2572b009 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 21518 T4126 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty2/index
[junit4:junit4]   2> 21519 T4116 C305 P13288 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:13285/ddr/o/collection1/, StdNode: http://127.0.0.1:13291/ddr/o/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4]   2> 21521 T4105 C302 P13285 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 21521 T4130 C301 P13291 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 21528 T4105 C302 P13285 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6684277a lockFactory=org.apache.lucene.store.NativeFSLockFactory@20d2e6f0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6684277a lockFactory=org.apache.lucene.store.NativeFSLockFactory@20d2e6f0),segFN=segments_3,generation=3,filenames=[_0.fnm, _0_TestBloomFilteredLucene41Postings_0.blm, _0_Lucene42_0.dvd, _0_Lucene41_0.pos, _0_TestBloomFilteredLucene41Postings_0.tim, _0_Memory_0.ram, _0_Lucene42_0.dvm, _0_TestBloomFilteredLucene41Postings_0.tip, _0.nvm, _0_TestBloomFilteredLucene41Postings_0.pos, _0_MockRandom_0.tip, _0_MockRandom_0.sd, _0_Lucene41_0.doc, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0.nvd, _0_TestBloomFilteredLucene41Postings_0.doc, _0.fdx, _0.si, _0_MockRandom_0.tim, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, segments_3]
[junit4:junit4]   2> 21529 T4105 C302 P13285 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0.fnm, _0_TestBloomFilteredLucene41Postings_0.blm, _0_Lucene42_0.dvd, _0_Lucene41_0.pos, _0_TestBloomFilteredLucene41Postings_0.tim, _0_Memory_0.ram, _0_Lucene42_0.dvm, _0_TestBloomFilteredLucene41Postings_0.tip, _0.nvm, _0_TestBloomFilteredLucene41Postings_0.pos, _0_MockRandom_0.tip, _0_MockRandom_0.sd, _0_Lucene41_0.doc, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0.nvd, _0_TestBloomFilteredLucene41Postings_0.doc, _0.fdx, _0.si, _0_MockRandom_0.tim, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, segments_3]
[junit4:junit4]   2> 21529 T4130 C301 P13291 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3fa09ae5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1d1644c1),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3fa09ae5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1d1644c1),segFN=segments_3,generation=3,filenames=[_0_Lucene42_0.dvd, _0_TestBloomFilteredLucene41Postings_0.tim, _0_Lucene41_0.pos, _0_Lucene42_0.dvm, _0_TestBloomFilteredLucene41Postings_0.tip, _0_TestBloomFilteredLucene41Postings_0.pos, _0.nvd, _0.si, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0_MockRandom_0.tib, _0.fnm, _0_TestBloomFilteredLucene41Postings_0.blm, _0_Memory_0.ram, _0.nvm, _0_MockRandom_0.skp, _0_MockRandom_0.sd, _0_MockRandom_0.frq, _0_MockRandom_0.tiv, _0_Lucene41_0.doc, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0_TestBloomFilteredLucene41Postings_0.doc, _0.fdx, _0_MockRandom_0.pyl, _0.fdt, segments_3]
[junit4:junit4]   2> 21530 T4130 C301 P13291 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0_Lucene42_0.dvd, _0_TestBloomFilteredLucene41Postings_0.tim, _0_Lucene41_0.pos, _0_Lucene42_0.dvm, _0_TestBloomFilteredLucene41Postings_0.tip, _0_TestBloomFilteredLucene41Postings_0.pos, _0.nvd, _0.si, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0_MockRandom_0.tib, _0.fnm, _0_TestBloomFilteredLucene41Postings_0.blm, _0_Memory_0.ram, _0.nvm, _0_MockRandom_0.skp, _0_MockRandom_0.sd, _0_MockRandom_0.frq, _0_MockRandom_0.tiv, _0_Lucene41_0.doc, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0_TestBloomFilteredLucene41Postings_0.doc, _0.fdx, _0_MockRandom_0.pyl, _0.fdt, segments_3]
[junit4:junit4]   2> 21530 T4105 C302 P13285 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty1
[junit4:junit4]   2> 21531 T4130 C301 P13291 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3
[junit4:junit4]   2> 21532 T4105 C302 P13285 oass.SolrIndexSearcher.<init> Opening Searcher@5544243f main
[junit4:junit4]   2> 21533 T4105 C302 P13285 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty1/index
[junit4:junit4]   2> 21533 T4130 C301 P13291 oass.SolrIndexSearcher.<init> Opening Searcher@2a1803d5 main
[junit4:junit4]   2> 21533 T4105 C302 P13285 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 21534 T4111 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5544243f main{StandardDirectoryReader(segments_3:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 21534 T4130 C301 P13291 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 21534 T4141 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2a1803d5 main{StandardDirectoryReader(segments_3:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 21534 T4111 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty1/index
[junit4:junit4]   2> 21535 T4141 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362157158654/jetty3/index.20130301125939212
[junit4:junit4]   2> 21535 T4105 C302 P13285 /update {waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 14
[junit4:junit4]   2> 21535 T4130 C301 P13291 /update {waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 14
[junit4:junit4]   2> 21536 T4116 C305 P13288 /update {waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 25
[junit4:junit4]   2> 21537 T4068 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):230
[junit4:junit4]   2> 21538 T4068 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 21539 T4068 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4]   2> 21542 T4080 C304 P13281 REQ /select {q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 21542 T4068 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13278/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@ea3aa8a
[junit4:junit4]   2> 21544 T4068 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 21544 T4150 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13278. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 21545 T4150 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13278, initiating session
[junit4:junit4]   2> 21545 T4070 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:13307
[junit4:junit4]   2> 21545 T4070 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:13307
[junit4:junit4]   2> 21571 T4072 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d26e4c104000b with negotiated timeout 10000 for client /140.211.11.196:13307
[junit4:junit4]   2> 21571 T4150 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13278, sessionid = 0x13d26e4c104000b, negotiated timeout = 10000
[junit4:junit4]   2> 21572 T4151 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ea3aa8a name:ZooKeeperConnection Watcher:127.0.0.1:13278/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 21572 T4068 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 21573 T4068 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 21575 T4073 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d26e4c104000b
[junit4:junit4]   2> 21576 T4151 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 21576 T4070 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:13307 which had sessionid 0x13d26e4c104000b
[junit4:junit4]   2> 21576 T4068 oaz.ZooKeeper.close Session: 0x13d26e4c104000b closed
[junit4:junit4]   2> 21578 T4099 C302 P13285 REQ /select {q=*:*&distrib=false&wt=javabin&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 21581 T4117 C305 P13288 REQ /select {q=*:*&distrib=false&wt=javabin&version=2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 21585 T4118 C305 P13288 REQ /select {NOW=1362157180231&shard.url=127.0.0.1:13288/ddr/o/collection1/&fl=id,score&start=0&q=*:*&distrib=false&wt=javabin&isShard=true&fsv=true&version=2&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 21585 T4131 C301 P13291 REQ /select {NOW=1362157180231&shard.url=127.0.0.1:13285/ddr/o/collection1/|127.0.0.1:13291/ddr/o/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> 21589 T4131 C301 P13291 REQ /select {NOW=1362157180231&shard.url=127.0.0.1:13285/ddr/o/collection1/|127.0.0.1:13291/ddr/o/collection1/&ids=1&q=*:*&distrib=false&wt=javabin&isShard=true&version=2} status=0 QTime=0 
[junit4:junit4]   2> 21590 T4102 C302 P13285 REQ /select {q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=8 
[junit4:junit4]   2> 21597 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[2 (1428325327429435392)]} 0 4
[junit4:junit4]   2> 21604 T4119 C305 P13288 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[2 (1428325327437824000)]} 0 3
[junit4:junit4]   2> 21604 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[2]} 0 5
[junit4:junit4]   2> 21609 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[3 (1428325327444115456)]} 0 2
[junit4:junit4]   2> 21614 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[3 (1428325327449358336)]} 0 2
[junit4:junit4]   2> 21619 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[4 (1428325327454601216)]} 0 2
[junit4:junit4]   2> 21634 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[4 (1428325327460892672)]} 0 3
[junit4:junit4]   2> 21635 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[4 (1428325327460892672)]} 0 12
[junit4:junit4]   2> 21642 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[5 (1428325327477669888)]} 0 4
[junit4:junit4]   2> 21649 T4119 C305 P13288 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[5 (1428325327486058496)]} 0 2
[junit4:junit4]   2> 21650 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[5]} 0 5
[junit4:junit4]   2> 21656 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[6 (1428325327492349952)]} 0 3
[junit4:junit4]   2> 21663 T4119 C305 P13288 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[6 (1428325327500738560)]} 0 2
[junit4:junit4]   2> 21664 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[6]} 0 5
[junit4:junit4]   2> 21669 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[7 (1428325327505981440)]} 0 3
[junit4:junit4]   2> 21674 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[7 (1428325327512272896)]} 0 2
[junit4:junit4]   2> 21680 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[8 (1428325327518564352)]} 0 3
[junit4:junit4]   2> 21692 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[8 (1428325327526952960)]} 0 2
[junit4:junit4]   2> 21693 T4105 C302 P13285 /update {distrib.from=http://127.0.0.1:13288/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[8 (1428325327526952960)]} 0 7
[junit4:junit4]   2> 21693 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[8]} 0 9
[junit4:junit4]   2> 21699 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[9 (1428325327537438720)]} 0 3
[junit4:junit4]   2> 21704 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[9 (1428325327543730176)]} 0 2
[junit4:junit4]   2> 21710 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[10 (1428325327550021632)]} 0 3
[junit4:junit4]   2> 21720 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10 (1428325327556313088)]} 0 2
[junit4:junit4]   2> 21720 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[10 (1428325327556313088)]} 0 6
[junit4:junit4]   2> 21728 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[11 (1428325327565750272)]} 0 5
[junit4:junit4]   2> 21739 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[11 (1428325327574138880)]} 0 3
[junit4:junit4]   2> 21740 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[11 (1428325327574138880)]} 0 9
[junit4:junit4]   2> 21748 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[12 (1428325327586721792)]} 0 5
[junit4:junit4]   2> 21759 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[12 (1428325327595110400)]} 0 3
[junit4:junit4]   2> 21760 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[12 (1428325327595110400)]} 0 9
[junit4:junit4]   2> 21767 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[13 (1428325327608741888)]} 0 4
[junit4:junit4]   2> 21779 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[13 (1428325327618179072)]} 0 2
[junit4:junit4]   2> 21780 T4105 C302 P13285 /update {distrib.from=http://127.0.0.1:13288/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[13 (1428325327618179072)]} 0 7
[junit4:junit4]   2> 21780 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[13]} 0 9
[junit4:junit4]   2> 21786 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[14 (1428325327628664832)]} 0 3
[junit4:junit4]   2> 21797 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[14 (1428325327638102016)]} 0 1
[junit4:junit4]   2> 21798 T4105 C302 P13285 /update {distrib.from=http://127.0.0.1:13288/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[14 (1428325327638102016)]} 0 6
[junit4:junit4]   2> 21799 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[14]} 0 10
[junit4:junit4]   2> 21804 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[15 (1428325327648587776)]} 0 2
[junit4:junit4]   2> 21812 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[15 (1428325327653830656)]} 0 1
[junit4:junit4]   2> 21813 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[15 (1428325327653830656)]} 0 6
[junit4:junit4]   2> 21819 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[16 (1428325327663267840)]} 0 3
[junit4:junit4]   2> 21826 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[16 (1428325327668510720)]} 0 1
[junit4:junit4]   2> 21827 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[16 (1428325327668510720)]} 0 6
[junit4:junit4]   2> 21838 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[17 (1428325327678996480)]} 0 8
[junit4:junit4]   2> 21844 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[17 (1428325327689482240)]} 0 3
[junit4:junit4]   2> 21850 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[100 (1428325327695773696)]} 0 3
[junit4:junit4]   2> 21860 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[100 (1428325327704162304)]} 0 2
[junit4:junit4]   2> 21861 T4105 C302 P13285 /update {distrib.from=http://127.0.0.1:13288/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[100 (1428325327704162304)]} 0 6
[junit4:junit4]   2> 21861 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[100]} 0 8
[junit4:junit4]   2> 21867 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[101 (1428325327713599488)]} 0 3
[junit4:junit4]   2> 21876 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[101 (1428325327719890944)]} 0 2
[junit4:junit4]   2> 21876 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[101 (1428325327719890944)]} 0 6
[junit4:junit4]   2> 21882 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[102 (1428325327729328128)]} 0 3
[junit4:junit4]   2> 21892 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[102 (1428325327737716736)]} 0 2
[junit4:junit4]   2> 21893 T4105 C302 P13285 /update {distrib.from=http://127.0.0.1:13288/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[102 (1428325327737716736)]} 0 6
[junit4:junit4]   2> 21893 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[102]} 0 8
[junit4:junit4]   2> 21899 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[103 (1428325327747153920)]} 0 3
[junit4:junit4]   2> 21906 T4119 C305 P13288 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[103 (1428325327756591104)]} 0 1
[junit4:junit4]   2> 21906 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[103]} 0 4
[junit4:junit4]   2> 21913 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[104 (1428325327761833984)]} 0 3
[junit4:junit4]   2> 21917 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[104 (1428325327768125440)]} 0 1
[junit4:junit4]   2> 21922 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[105 (1428325327772319744)]} 0 3
[junit4:junit4]   2> 21926 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[105 (1428325327777562624)]} 0 1
[junit4:junit4]   2> 21932 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[106 (1428325327782805504)]} 0 3
[junit4:junit4]   2> 21936 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[106 (1428325327788048384)]} 0 1
[junit4:junit4]   2> 21941 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[107 (1428325327791194112)]} 0 3
[junit4:junit4]   2> 21951 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[107 (1428325327799582720)]} 0 2
[junit4:junit4]   2> 21952 T4105 C302 P13285 /update {distrib.from=http://127.0.0.1:13288/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[107 (1428325327799582720)]} 0 6
[junit4:junit4]   2> 21952 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[107]} 0 8
[junit4:junit4]   2> 21958 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[108 (1428325327809019904)]} 0 3
[junit4:junit4]   2> 21968 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[108 (1428325327817408512)]} 0 2
[junit4:junit4]   2> 21969 T4105 C302 P13285 /update {distrib.from=http://127.0.0.1:13288/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[108 (1428325327817408512)]} 0 6
[junit4:junit4]   2> 21969 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[108]} 0 8
[junit4:junit4]   2> 21975 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[109 (1428325327826845696)]} 0 3
[junit4:junit4]   2> 21985 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[109 (1428325327835234304)]} 0 2
[junit4:junit4]   2> 21986 T4105 C302 P13285 /update {distrib.from=http://127.0.0.1:13288/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[109 (1428325327835234304)]} 0 6
[junit4:junit4]   2> 21986 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[109]} 0 8
[junit4:junit4]   2> 21992 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[110 (1428325327845720064)]} 0 3
[junit4:junit4]   2> 22002 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[110 (1428325327853060096)]} 0 2
[junit4:junit4]   2> 22003 T4105 C302 P13285 /update {distrib.from=http://127.0.0.1:13288/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[110 (1428325327853060096)]} 0 6
[junit4:junit4]   2> 22003 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[110]} 0 8
[junit4:junit4]   2> 22008 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[111 (1428325327862497280)]} 0 2
[junit4:junit4]   2> 22017 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[111 (1428325327868788736)]} 0 2
[junit4:junit4]   2> 22018 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[111 (1428325327868788736)]} 0 6
[junit4:junit4]   2> 22024 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[112 (1428325327878225920)]} 0 3
[junit4:junit4]   2> 22028 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[112 (1428325327884517376)]} 0 1
[junit4:junit4]   2> 22033 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[113 (1428325327888711680)]} 0 3
[junit4:junit4]   2> 22041 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[113 (1428325327893954560)]} 0 2
[junit4:junit4]   2> 22042 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[113 (1428325327893954560)]} 0 6
[junit4:junit4]   2> 22048 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[114 (1428325327902343168)]} 0 4
[junit4:junit4]   2> 22055 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[114 (1428325327909683200)]} 0 1
[junit4:junit4]   2> 22056 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[114 (1428325327909683200)]} 0 5
[junit4:junit4]   2> 22061 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[115 (1428325327918071808)]} 0 2
[junit4:junit4]   2> 22065 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[115 (1428325327923314688)]} 0 1
[junit4:junit4]   2> 22070 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[116 (1428325327927508992)]} 0 2
[junit4:junit4]   2> 22078 T4119 C305 P13288 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[116 (1428325327936946176)]} 0 2
[junit4:junit4]   2> 22079 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[116]} 0 6
[junit4:junit4]   2> 22083 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[117 (1428325327942189056)]} 0 1
[junit4:junit4]   2> 22090 T4119 C305 P13288 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[117 (1428325327949529088)]} 0 1
[junit4:junit4]   2> 22090 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[117]} 0 4
[junit4:junit4]   2> 22094 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[118 (1428325327953723392)]} 0 1
[junit4:junit4]   2> 22102 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[118 (1428325327958966272)]} 0 1
[junit4:junit4]   2> 22103 T4105 C302 P13285 /update {distrib.from=http://127.0.0.1:13288/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[118 (1428325327958966272)]} 0 5
[junit4:junit4]   2> 22104 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[118]} 0 8
[junit4:junit4]   2> 22108 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[119 (1428325327968403456)]} 0 1
[junit4:junit4]   2> 22111 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[119 (1428325327971549184)]} 0 1
[junit4:junit4]   2> 22115 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[120 (1428325327975743488)]} 0 1
[junit4:junit4]   2> 22118 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[120 (1428325327978889216)]} 0 1
[junit4:junit4]   2> 22122 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[121 (1428325327983083520)]} 0 1
[junit4:junit4]   2> 22128 T4119 C305 P13288 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[121 (1428325327989374976)]} 0 1
[junit4:junit4]   2> 22128 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[121]} 0 3
[junit4:junit4]   2> 22132 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[122 (1428325327993569280)]} 0 1
[junit4:junit4]   2> 22141 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[122 (1428325327999860736)]} 0 1
[junit4:junit4]   2> 22142 T4105 C302 P13285 /update {distrib.from=http://127.0.0.1:13288/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[122 (1428325327999860736)]} 0 5
[junit4:junit4]   2> 22142 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[122]} 0 7
[junit4:junit4]   2> 22146 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[123 (1428325328008249344)]} 0 1
[junit4:junit4]   2> 22155 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[123 (1428325328014540800)]} 0 1
[junit4:junit4]   2> 22156 T4105 C302 P13285 /update {distrib.from=http://127.0.0.1:13288/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[123 (1428325328014540800)]} 0 5
[junit4:junit4]   2> 22157 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[123]} 0 8
[junit4:junit4]   2> 22161 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[124 (1428325328023977984)]} 0 1
[junit4:junit4]   2> 22168 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[124 (1428325328028172288)]} 0 1
[junit4:junit4]   2> 22169 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[124 (1428325328028172288)]} 0 5
[junit4:junit4]   2> 22173 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[125 (1428325328036560896)]} 0 1
[junit4:junit4]   2> 22180 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[125 (1428325328040755200)]} 0 1
[junit4:junit4]   2> 22181 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[125 (1428325328040755200)]} 0 5
[junit4:junit4]   2> 22185 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[126 (1428325328049143808)]} 0 1
[junit4:junit4]   2> 22191 T4119 C305 P13288 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[126 (1428325328055435264)]} 0 1
[junit4:junit4]   2> 22191 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[126]} 0 3
[junit4:junit4]   2> 22195 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[127 (1428325328059629568)]} 0 1
[junit4:junit4]   2> 22199 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[127 (1428325328063823872)]} 0 1
[junit4:junit4]   2> 22203 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[128 (1428325328068018176)]} 0 1
[junit4:junit4]   2> 22209 T4119 C305 P13288 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[128 (1428325328074309632)]} 0 1
[junit4:junit4]   2> 22209 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[128]} 0 3
[junit4:junit4]   2> 22213 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[129 (1428325328078503936)]} 0 1
[junit4:junit4]   2> 22220 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[129 (1428325328082698240)]} 0 1
[junit4:junit4]   2> 22221 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[129 (1428325328082698240)]} 0 5
[junit4:junit4]   2> 22225 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[130 (1428325328091086848)]} 0 1
[junit4:junit4]   2> 22228 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[130 (1428325328094232576)]} 0 1
[junit4:junit4]   2> 22232 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[131 (1428325328098426880)]} 0 1
[junit4:junit4]   2> 22235 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[131 (1428325328101572608)]} 0 1
[junit4:junit4]   2> 22239 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[132 (1428325328105766912)]} 0 1
[junit4:junit4]   2> 22245 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[132 (1428325328108912640)]} 0 1
[junit4:junit4]   2> 22246 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[132 (1428325328108912640)]} 0 5
[junit4:junit4]   2> 22250 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[133 (1428325328117301248)]} 0 1
[junit4:junit4]   2> 22258 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[133 (1428325328122544128)]} 0 1
[junit4:junit4]   2> 22259 T4105 C302 P13285 /update {distrib.from=http://127.0.0.1:13288/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[133 (1428325328122544128)]} 0 5
[junit4:junit4]   2> 22260 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[133]} 0 8
[junit4:junit4]   2> 22264 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[134 (1428325328131981312)]} 0 1
[junit4:junit4]   2> 22270 T4119 C305 P13288 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[134 (1428325328138272768)]} 0 1
[junit4:junit4]   2> 22270 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[134]} 0 3
[junit4:junit4]   2> 22274 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[135 (1428325328142467072)]} 0 1
[junit4:junit4]   2> 22284 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[135 (1428325328149807104)]} 0 1
[junit4:junit4]   2> 22285 T4105 C302 P13285 /update {distrib.from=http://127.0.0.1:13288/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[135 (1428325328149807104)]} 0 5
[junit4:junit4]   2> 22286 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[135]} 0 9
[junit4:junit4]   2> 22289 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[136 (1428325328158195712)]} 0 1
[junit4:junit4]   2> 22293 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[136 (1428325328162390016)]} 0 1
[junit4:junit4]   2> 22296 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[137 (1428325328165535744)]} 0 1
[junit4:junit4]   2> 22303 T4119 C305 P13288 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[137 (1428325328172875776)]} 0 1
[junit4:junit4]   2> 22303 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[137]} 0 4
[junit4:junit4]   2> 22307 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[138 (1428325328177070080)]} 0 1
[junit4:junit4]   2> 22319 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[138 (1428325328185458688)]} 0 1
[junit4:junit4]   2> 22320 T4105 C302 P13285 /update {distrib.from=http://127.0.0.1:13288/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[138 (1428325328185458688)]} 0 6
[junit4:junit4]   2> 22321 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[138]} 0 10
[junit4:junit4]   2> 22325 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[139 (1428325328195944448)]} 0 1
[junit4:junit4]   2> 22331 T4119 C305 P13288 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[139 (1428325328202235904)]} 0 1
[junit4:junit4]   2> 22331 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[139]} 0 3
[junit4:junit4]   2> 22335 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[140 (1428325328206430208)]} 0 1
[junit4:junit4]   2> 22340 T4119 C305 P13288 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[140 (1428325328211673088)]} 0 1
[junit4:junit4]   2> 22340 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[140]} 0 3
[junit4:junit4]   2> 22344 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[141 (1428325328215867392)]} 0 1
[junit4:junit4]   2> 22350 T4119 C305 P13288 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[141 (1428325328222158848)]} 0 1
[junit4:junit4]   2> 22350 T4102 C302 P13285 /update {wt=javabin&version=2} {add=[141]} 0 3
[junit4:junit4]   2> 22354 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[142 (1428325328226353152)]} 0 1
[junit4:junit4]   2> 22358 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[142 (1428325328230547456)]} 0 1
[junit4:junit4]   2> 22362 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[143 (1428325328234741760)]} 0 1
[junit4:junit4]   2> 22365 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[143 (1428325328237887488)]} 0 1
[junit4:junit4]   2> 22368 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[144 (1428325328241033216)]} 0 1
[junit4:junit4]   2> 22372 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[144 (1428325328245227520)]} 0 1
[junit4:junit4]   2> 22375 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[145 (1428325328248373248)]} 0 1
[junit4:junit4]   2> 22378 T4116 C305 P13288 /update {wt=javabin&version=2} {add=[145 (1428325328251518976)]} 0 1
[junit4:junit4]   2> 22381 T4080 C304 P13281 /update {wt=javabin&version=2} {add=[146 (1428325328254664704)]} 0 1
[junit4:junit4]   2> 22390 T4129 C301 P13291 /update {distrib.from=http://127.0.0.1:13285/ddr/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[146 (1428325328259907584)]} 0 2
[junit4:junit4]   2> 22390 T4105 C302 P13285 /update {distrib.from=http://127.0.0.1:13288/ddr/o/collection1/&update.distrib=TOLEADER&wt

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

kClient.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> 86661 T4139 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> 86661 T4139 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 86661 T4139 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 86661 T4139 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> 86662 T4139 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 86662 T4139 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> 86662 T4139 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> NOTE: test params are: codec=Lucene42: {foo_b=PostingsFormat(name=TestBloomFilteredLucene41Postings), n_f1=PostingsFormat(name=Memory doPackFST= true), foo_d=Lucene41(blocksize=128), foo_f=PostingsFormat(name=TestBloomFilteredLucene41Postings), n_tl1=PostingsFormat(name=Memory doPackFST= true), n_d1=PostingsFormat(name=MockRandom), rnd_b=Lucene41(blocksize=128), intDefault=PostingsFormat(name=MockRandom), n_td1=PostingsFormat(name=Memory doPackFST= true), timestamp=PostingsFormat(name=MockRandom), id=Lucene41(blocksize=128), range_facet_sl=PostingsFormat(name=TestBloomFilteredLucene41Postings), range_facet_si=PostingsFormat(name=Memory doPackFST= true), oddField_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), multiDefault=PostingsFormat(name=Memory doPackFST= true), n_tf1=PostingsFormat(name=MockRandom), n_dt1=PostingsFormat(name=Memory doPackFST= true), range_facet_l=PostingsFormat(name=MockRandom), n_ti1=Lucene41(blocksize=128), text=PostingsFormat(name=TestBloomFilteredLucene41Postings), _version_=PostingsFormat(name=MockRandom), SubjectTerms_mfacet=PostingsFormat(name=MockRandom), a_t=PostingsFormat(name=MockRandom), n_tdt1=PostingsFormat(name=MockRandom), other_tl1=PostingsFormat(name=MockRandom), n_l1=PostingsFormat(name=MockRandom), a_si=PostingsFormat(name=Memory doPackFST= true)}, docValues:{timestamp=DocValuesFormat(name=Lucene42)}, sim=DefaultSimilarity, locale=sq_AL, timezone=America/Tortola
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Oracle Corporation 1.7.0_09 (64-bit)/cpus=16,threads=3,free=263461552,total=403701760
[junit4:junit4]   2> NOTE: All tests run in this JVM: [ClusterStateTest, ResponseLogComponentTest, DisMaxRequestHandlerTest, OpenExchangeRatesOrgProviderTest, TestOmitPositions, PrimitiveFieldTypeTest, LukeRequestHandlerTest, TestFunctionQuery, URLClassifyProcessorTest, TestDFRSimilarityFactory, IndexSchemaTest, TestRemoteStreaming, IndexSchemaRuntimeFieldTest, TestJmxIntegration, HighlighterTest, TestCharFilters, TestRTGBase, HardAutoCommitTest, LegacyHTMLStripCharFilterTest, BadIndexSchemaTest, TestUtils, TestZkChroot, OverseerTest, OutputWriterTest, PolyFieldTest, SchemaVersionSpecificBehaviorTest, TestMultiCoreConfBootstrap, TestSolrCoreProperties, FullSolrCloudDistribCmdsTest, SynonymTokenizerTest, TermVectorComponentTest, ZkNodePropsTest, TestTrie, SignatureUpdateProcessorFactoryTest, TestUpdate, TestReplicationHandler, SolrIndexSplitterTest, TestWriterPerf, UUIDFieldTest, LeaderElectionTest, ZkSolrClientTest, DocumentAnalysisRequestHandlerTest, TestBM25SimilarityFactory, TestPluginEnable, FieldMutatingUpdateProcessorTest, TestDocSet, StatsComponentTest, SuggesterTSTTest, BasicFunctionalityTest, TestHashPartitioner, TestSolrDeletionPolicy1, CollectionsAPIDistributedZkTest, IndexReaderFactoryTest, BasicZkTest, XmlUpdateRequestHandlerTest, TestAnalyzedSuggestions, QueryEqualityTest, TestSolrJ, DistributedQueryElevationComponentTest, TestPhraseSuggestions, PeerSyncTest, ShardRoutingTest, RecoveryZkTest, LeaderElectionIntegrationTest, DistributedSpellCheckComponentTest, TestRealTimeGet, ZkControllerTest, TestDistributedGrouping, TestRandomFaceting, TestDistributedSearch, SoftAutoCommitTest, AutoCommitTest, TestFaceting, TestRecovery, SolrCoreTest, IndexBasedSpellCheckerTest, DirectUpdateHandlerTest, TestCoreContainer, TestSort, TestGroupingSearch, DirectSolrSpellCheckerTest, ConvertedLegacyTest, SortByFunctionTest, TestBinaryResponseWriter, SolrRequestParserTest, DirectSolrConnectionTest, CacheHeaderTest, TestWordDelimiterFilterFactory, TestCSVLoader, TestCSVResponseWriter, DocumentBuilderTest, MBeansHandlerTest, QueryParsingTest, SolrInfoMBeanTest, XsltUpdateRequestHandlerTest, MinimalSchemaTest, StandardRequestHandlerTest, PingRequestHandlerTest, SuggesterWFSTTest, TestSurroundQueryParser, DirectUpdateHandlerOptimizeTest, TestSolrQueryParser, SolrPluginUtilsTest, TestValueSourceCache, FastVectorHighlighterTest, TestReversedWildcardFilterFactory, DebugComponentTest, JSONWriterTest, ReturnFieldsTest, RequiredFieldsTest, SuggesterFSTTest, TestArbitraryIndexDir, TestQueryUtils, LoggingHandlerTest, SolrCmdDistributorTest, UpdateParamsTest, SuggesterTest, CSVRequestHandlerTest, ShowFileRequestHandlerTest, TestSearchPerf, NotRequiredUniqueKeyTest, TestFoldingMultitermQuery, SolrCoreCheckLockOnStartupTest, TestLuceneMatchVersion, UpdateRequestProcessorFactoryTest, TestPropInject, NoCacheHeaderTest, TestBinaryField, HighlighterConfigTest, TestSolrDeletionPolicy2, TestPropInjectDefaults, TestMergePolicyConfig, TestQuerySenderListener, TestCollationField, SolrIndexConfigTest, NumericFieldsTest, TestNumberUtils, MultiTermTest, TestConfig, EchoParamsTest, TestPerFieldSimilarity, TestIBSimilarityFactory, TestCodecSupport, TestDefaultSimilarityFactory, TimeZoneUtilsTest, DateMathParserTest, PluginInfoTest, PrimUtilsTest, FileUtilsTest, TestSystemIdResolver, TestSolrXMLSerializer, DateFieldTest, SpellingQueryConverterTest, TestSuggestSpellingConverter, TestBadConfig, DOMUtilTest, TestLRUCache, RAMDirectoryFactoryTest, ChaosMonkeyNothingIsSafeTest, PreAnalyzedFieldTest, AnalysisAfterCoreReloadTest, TestDocumentBuilder, BasicDistributedZk2Test]
[junit4:junit4] Completed on J1 in 87.49s, 1 test, 1 error <<< FAILURES!

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

Total time: 50 minutes 27 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