You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/03/19 21:51:39 UTC

[JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.8.0-ea-b79) - Build # 4782 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/4782/
Java: 64bit/jdk1.8.0-ea-b79 -XX:+UseParallelGC

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

Error Message:
Still found shard2 in collection test_unload_shard_and_collection

Stack Trace:
java.lang.AssertionError: Still found shard2 in collection test_unload_shard_and_collection
	at __randomizedtesting.SeedInfo.seed([E9E1A105D350FB69:68072F1DA40F9B55]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.UnloadDistributedZkTest.testUnloadShardAndCollection(UnloadDistributedZkTest.java:124)
	at org.apache.solr.cloud.UnloadDistributedZkTest.doTest(UnloadDistributedZkTest.java:77)
	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:487)
	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 9306 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.UnloadDistributedZkTest
[junit4:junit4]   2> 0 T1766 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /x_oin/u
[junit4:junit4]   2> 4 T1766 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990
[junit4:junit4]   2> 4 T1766 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 5 T1767 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 6 T1767 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 6 T1767 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4]   2> 6 T1767 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4]   2> 6 T1767 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 7 T1767 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1363725861990/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4]   2> 105 T1766 oasc.ZkTestServer.run start zk server on port:40338
[junit4:junit4]   2> 105 T1766 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:40338 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@236f61d5
[junit4:junit4]   2> 106 T1766 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 106 T1772 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:40338. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 107 T1772 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:40338, initiating session
[junit4:junit4]   2> 107 T1768 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:55540
[junit4:junit4]   2> 107 T1768 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:55540
[junit4:junit4]   2> 107 T1770 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 110 T1770 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d846544690000 with negotiated timeout 10000 for client /127.0.0.1:55540
[junit4:junit4]   2> 110 T1772 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:40338, sessionid = 0x13d846544690000, negotiated timeout = 10000
[junit4:junit4]   2> 110 T1773 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@236f61d5 name:ZooKeeperConnection Watcher:127.0.0.1:40338 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 110 T1766 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 110 T1766 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 112 T1771 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d846544690000
[junit4:junit4]   2> 113 T1773 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 113 T1768 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:55540 which had sessionid 0x13d846544690000
[junit4:junit4]   2> 113 T1766 oaz.ZooKeeper.close Session: 0x13d846544690000 closed
[junit4:junit4]   2> 113 T1766 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:40338/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@2da88bc8
[junit4:junit4]   2> 114 T1766 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 114 T1774 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:40338. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 115 T1774 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:40338, initiating session
[junit4:junit4]   2> 115 T1768 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:55541
[junit4:junit4]   2> 115 T1768 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:55541
[junit4:junit4]   2> 115 T1770 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d846544690001 with negotiated timeout 10000 for client /127.0.0.1:55541
[junit4:junit4]   2> 115 T1774 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:40338, sessionid = 0x13d846544690001, negotiated timeout = 10000
[junit4:junit4]   2> 116 T1775 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2da88bc8 name:ZooKeeperConnection Watcher:127.0.0.1:40338/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 116 T1766 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 116 T1766 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 119 T1766 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 121 T1766 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 123 T1766 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 125 T1766 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 125 T1766 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 128 T1766 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 129 T1766 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 132 T1766 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 132 T1766 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 134 T1766 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 134 T1766 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 136 T1766 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 137 T1766 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 139 T1766 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 140 T1766 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 142 T1766 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 142 T1766 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 145 T1766 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 145 T1766 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 147 T1766 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 148 T1766 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 150 T1771 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d846544690001
[junit4:junit4]   2> 150 T1775 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 150 T1768 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:55541 which had sessionid 0x13d846544690001
[junit4:junit4]   2> 150 T1766 oaz.ZooKeeper.close Session: 0x13d846544690001 closed
[junit4:junit4]   2> 205 T1766 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 209 T1766 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47983
[junit4:junit4]   2> 210 T1766 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 210 T1766 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 211 T1766 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1363725862137
[junit4:junit4]   2> 211 T1766 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1363725862137/solr.xml
[junit4:junit4]   2> 211 T1766 oasc.CoreContainer.<init> New CoreContainer 1289811146
[junit4:junit4]   2> 212 T1766 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1363725862137/'
[junit4:junit4]   2> 212 T1766 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1363725862137/'
[junit4:junit4]   2> 228 T1766 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 228 T1766 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 228 T1766 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 228 T1766 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 229 T1766 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 229 T1766 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 229 T1766 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 230 T1766 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 230 T1766 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 230 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 235 T1766 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 244 T1766 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:40338/solr
[junit4:junit4]   2> 244 T1766 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 244 T1766 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:40338 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@50d0f18
[junit4:junit4]   2> 245 T1766 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 245 T1785 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:40338. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 246 T1785 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:40338, initiating session
[junit4:junit4]   2> 246 T1768 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:55542
[junit4:junit4]   2> 246 T1768 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:55542
[junit4:junit4]   2> 249 T1770 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d846544690002 with negotiated timeout 20000 for client /127.0.0.1:55542
[junit4:junit4]   2> 249 T1785 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:40338, sessionid = 0x13d846544690002, negotiated timeout = 20000
[junit4:junit4]   2> 249 T1786 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50d0f18 name:ZooKeeperConnection Watcher:127.0.0.1:40338 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 249 T1766 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 250 T1771 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d846544690002
[junit4:junit4]   2> 251 T1786 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 251 T1768 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:55542 which had sessionid 0x13d846544690002
[junit4:junit4]   2> 251 T1766 oaz.ZooKeeper.close Session: 0x13d846544690002 closed
[junit4:junit4]   2> 251 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 254 T1766 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:40338/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@6fee6169
[junit4:junit4]   2> 254 T1766 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 254 T1787 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:40338. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 255 T1787 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:40338, initiating session
[junit4:junit4]   2> 255 T1768 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:55543
[junit4:junit4]   2> 255 T1768 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:55543
[junit4:junit4]   2> 256 T1770 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d846544690003 with negotiated timeout 20000 for client /127.0.0.1:55543
[junit4:junit4]   2> 256 T1787 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:40338, sessionid = 0x13d846544690003, negotiated timeout = 20000
[junit4:junit4]   2> 256 T1788 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6fee6169 name:ZooKeeperConnection Watcher:127.0.0.1:40338/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 256 T1766 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 257 T1766 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4]   2> 259 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d846544690003 type:create cxid:0x7 zxid:0x1b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 260 T1766 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4]   2> 262 T1766 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 263 T1766 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47983_x_oin%2Fu
[junit4:junit4]   2> 264 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d846544690003 type:delete cxid:0x12 zxid:0x1e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:47983_x_oin%2Fu Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:47983_x_oin%2Fu
[junit4:junit4]   2> 264 T1766 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47983_x_oin%2Fu
[junit4:junit4]   2> 267 T1766 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 271 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d846544690003 type:delete cxid:0x20 zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 271 T1766 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 273 T1766 oasc.Overseer.start Overseer (id=89373138091573251-127.0.0.1:47983_x_oin%2Fu-n_0000000000) starting
[junit4:junit4]   2> 273 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d846544690003 type:create cxid:0x25 zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 274 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d846544690003 type:create cxid:0x26 zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 274 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d846544690003 type:create cxid:0x28 zxid:0x27 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 275 T1766 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4]   2> 277 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d846544690003 type:create cxid:0x2e zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 278 T1790 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 278 T1766 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 280 T1766 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4]   2> 281 T1766 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 283 T1789 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 284 T1766 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 284 T1766 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 285 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 287 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 287 T1766 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:40338/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@131a5f9a
[junit4:junit4]   2> 288 T1766 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 288 T1792 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:40338. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 289 T1792 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:40338, initiating session
[junit4:junit4]   2> 289 T1768 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:55544
[junit4:junit4]   2> 289 T1768 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:55544
[junit4:junit4]   2> 290 T1770 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d846544690004 with negotiated timeout 10000 for client /127.0.0.1:55544
[junit4:junit4]   2> 290 T1792 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:40338, sessionid = 0x13d846544690004, negotiated timeout = 10000
[junit4:junit4]   2> 290 T1793 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@131a5f9a name:ZooKeeperConnection Watcher:127.0.0.1:40338/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 290 T1766 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 291 T1766 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 293 T1766 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 348 T1766 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 350 T1766 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53441
[junit4:junit4]   2> 350 T1766 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 350 T1766 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 351 T1766 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1363725862279
[junit4:junit4]   2> 351 T1766 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1363725862279/solr.xml
[junit4:junit4]   2> 351 T1766 oasc.CoreContainer.<init> New CoreContainer 1035776844
[junit4:junit4]   2> 352 T1766 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1363725862279/'
[junit4:junit4]   2> 352 T1766 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1363725862279/'
[junit4:junit4]   2> 367 T1766 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 368 T1766 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 368 T1766 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 368 T1766 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 368 T1766 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 369 T1766 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 369 T1766 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 369 T1766 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 370 T1766 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 370 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 375 T1766 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 383 T1766 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:40338/solr
[junit4:junit4]   2> 384 T1766 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 384 T1766 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:40338 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@58f83451
[junit4:junit4]   2> 385 T1766 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 385 T1803 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:40338. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 385 T1803 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:40338, initiating session
[junit4:junit4]   2> 385 T1768 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:55545
[junit4:junit4]   2> 386 T1768 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:55545
[junit4:junit4]   2> 386 T1770 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d846544690005 with negotiated timeout 20000 for client /127.0.0.1:55545
[junit4:junit4]   2> 386 T1803 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:40338, sessionid = 0x13d846544690005, negotiated timeout = 20000
[junit4:junit4]   2> 387 T1804 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58f83451 name:ZooKeeperConnection Watcher:127.0.0.1:40338 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 387 T1766 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 388 T1771 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d846544690005
[junit4:junit4]   2> 389 T1804 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 389 T1768 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:55545 which had sessionid 0x13d846544690005
[junit4:junit4]   2> 389 T1766 oaz.ZooKeeper.close Session: 0x13d846544690005 closed
[junit4:junit4]   2> 389 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 391 T1766 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:40338/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@5998f3c8
[junit4:junit4]   2> 392 T1766 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 392 T1805 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:40338. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 393 T1805 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:40338, initiating session
[junit4:junit4]   2> 393 T1768 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:55546
[junit4:junit4]   2> 393 T1768 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:55546
[junit4:junit4]   2> 394 T1770 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d846544690006 with negotiated timeout 20000 for client /127.0.0.1:55546
[junit4:junit4]   2> 394 T1805 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:40338, sessionid = 0x13d846544690006, negotiated timeout = 20000
[junit4:junit4]   2> 394 T1806 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5998f3c8 name:ZooKeeperConnection Watcher:127.0.0.1:40338/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 394 T1766 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 395 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d846544690006 type:create cxid:0x1 zxid:0x30 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 396 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d846544690006 type:create cxid:0x3 zxid:0x31 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 397 T1766 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 1400 T1766 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53441_x_oin%2Fu
[junit4:junit4]   2> 1400 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d846544690006 type:delete cxid:0xd zxid:0x32 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:53441_x_oin%2Fu Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:53441_x_oin%2Fu
[junit4:junit4]   2> 1401 T1766 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53441_x_oin%2Fu
[junit4:junit4]   2> 1403 T1788 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 1403 T1793 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 1404 T1806 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 1407 T1766 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 1408 T1766 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 1408 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 1465 T1766 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 1467 T1766 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:42905
[junit4:junit4]   2> 1467 T1766 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 1468 T1766 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 1468 T1766 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1363725863396
[junit4:junit4]   2> 1468 T1766 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1363725863396/solr.xml
[junit4:junit4]   2> 1468 T1766 oasc.CoreContainer.<init> New CoreContainer 94487432
[junit4:junit4]   2> 1469 T1766 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1363725863396/'
[junit4:junit4]   2> 1469 T1766 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1363725863396/'
[junit4:junit4]   2> 1485 T1766 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 1485 T1766 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 1485 T1766 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 1486 T1766 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 1486 T1766 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 1486 T1766 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 1487 T1766 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 1487 T1766 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 1487 T1766 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 1487 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 1493 T1766 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 1501 T1766 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:40338/solr
[junit4:junit4]   2> 1501 T1766 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 1502 T1766 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:40338 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@7d7eaf01
[junit4:junit4]   2> 1503 T1766 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 1503 T1817 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:40338. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 1504 T1817 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:40338, initiating session
[junit4:junit4]   2> 1504 T1768 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:55548
[junit4:junit4]   2> 1504 T1768 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:55548
[junit4:junit4]   2> 1505 T1770 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d846544690007 with negotiated timeout 20000 for client /127.0.0.1:55548
[junit4:junit4]   2> 1505 T1817 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:40338, sessionid = 0x13d846544690007, negotiated timeout = 20000
[junit4:junit4]   2> 1505 T1818 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7d7eaf01 name:ZooKeeperConnection Watcher:127.0.0.1:40338 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 1505 T1766 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 1506 T1771 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d846544690007
[junit4:junit4]   2> 1507 T1818 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 1507 T1768 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:55548 which had sessionid 0x13d846544690007
[junit4:junit4]   2> 1507 T1766 oaz.ZooKeeper.close Session: 0x13d846544690007 closed
[junit4:junit4]   2> 1507 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 1509 T1766 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:40338/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@e11b36b
[junit4:junit4]   2> 1510 T1766 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 1510 T1819 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:40338. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 1511 T1819 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:40338, initiating session
[junit4:junit4]   2> 1511 T1768 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:55549
[junit4:junit4]   2> 1511 T1768 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:55549
[junit4:junit4]   2> 1512 T1770 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d846544690008 with negotiated timeout 20000 for client /127.0.0.1:55549
[junit4:junit4]   2> 1512 T1819 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:40338, sessionid = 0x13d846544690008, negotiated timeout = 20000
[junit4:junit4]   2> 1512 T1820 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e11b36b name:ZooKeeperConnection Watcher:127.0.0.1:40338/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 1512 T1766 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 1513 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d846544690008 type:create cxid:0x1 zxid:0x38 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1514 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d846544690008 type:create cxid:0x3 zxid:0x39 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1516 T1766 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 2518 T1766 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42905_x_oin%2Fu
[junit4:junit4]   2> 2519 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d846544690008 type:delete cxid:0xd zxid:0x3a txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:42905_x_oin%2Fu Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:42905_x_oin%2Fu
[junit4:junit4]   2> 2520 T1766 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42905_x_oin%2Fu
[junit4:junit4]   2> 2523 T1806 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 2523 T1788 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 2524 T1820 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 2524 T1793 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 2528 T1766 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 2528 T1766 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 2528 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2588 T1766 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 2590 T1766 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:45397
[junit4:junit4]   2> 2591 T1766 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 2591 T1766 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2591 T1766 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1363725864516
[junit4:junit4]   2> 2591 T1766 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1363725864516/solr.xml
[junit4:junit4]   2> 2592 T1766 oasc.CoreContainer.<init> New CoreContainer 1716652334
[junit4:junit4]   2> 2592 T1766 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1363725864516/'
[junit4:junit4]   2> 2592 T1766 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1363725864516/'
[junit4:junit4]   2> 2608 T1766 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 2609 T1766 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 2609 T1766 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 2609 T1766 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 2610 T1766 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 2610 T1766 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 2610 T1766 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 2610 T1766 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 2611 T1766 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 2611 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 2616 T1766 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 2625 T1766 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:40338/solr
[junit4:junit4]   2> 2625 T1766 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 2625 T1766 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:40338 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@4c574174
[junit4:junit4]   2> 2626 T1766 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2626 T1831 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:40338. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 2627 T1831 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:40338, initiating session
[junit4:junit4]   2> 2627 T1768 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:55550
[junit4:junit4]   2> 2627 T1768 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:55550
[junit4:junit4]   2> 2628 T1770 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d846544690009 with negotiated timeout 20000 for client /127.0.0.1:55550
[junit4:junit4]   2> 2628 T1831 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:40338, sessionid = 0x13d846544690009, negotiated timeout = 20000
[junit4:junit4]   2> 2628 T1832 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4c574174 name:ZooKeeperConnection Watcher:127.0.0.1:40338 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2628 T1766 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2630 T1771 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d846544690009
[junit4:junit4]   2> 2630 T1832 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 2630 T1768 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:55550 which had sessionid 0x13d846544690009
[junit4:junit4]   2> 2630 T1766 oaz.ZooKeeper.close Session: 0x13d846544690009 closed
[junit4:junit4]   2> 2631 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 2633 T1766 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:40338/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@2925b23b
[junit4:junit4]   2> 2634 T1766 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2634 T1833 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:40338. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 2635 T1833 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:40338, initiating session
[junit4:junit4]   2> 2635 T1768 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:55551
[junit4:junit4]   2> 2635 T1768 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:55551
[junit4:junit4]   2> 2636 T1770 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d84654469000a with negotiated timeout 20000 for client /127.0.0.1:55551
[junit4:junit4]   2> 2636 T1833 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:40338, sessionid = 0x13d84654469000a, negotiated timeout = 20000
[junit4:junit4]   2> 2636 T1834 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2925b23b name:ZooKeeperConnection Watcher:127.0.0.1:40338/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2637 T1766 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2638 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d84654469000a type:create cxid:0x1 zxid:0x40 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2639 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d84654469000a type:create cxid:0x3 zxid:0x41 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2641 T1766 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3644 T1766 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45397_x_oin%2Fu
[junit4:junit4]   2> 3645 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d84654469000a type:delete cxid:0xd zxid:0x42 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:45397_x_oin%2Fu Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:45397_x_oin%2Fu
[junit4:junit4]   2> 3646 T1766 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45397_x_oin%2Fu
[junit4:junit4]   2> 3650 T1793 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 3650 T1806 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 3650 T1788 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 3651 T1820 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 3651 T1834 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 3657 T1766 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 3658 T1766 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 3659 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 3729 T1766 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 3731 T1766 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51404
[junit4:junit4]   2> 3731 T1766 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 3731 T1766 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3732 T1766 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1363725865648
[junit4:junit4]   2> 3732 T1766 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1363725865648/solr.xml
[junit4:junit4]   2> 3732 T1766 oasc.CoreContainer.<init> New CoreContainer 1225379453
[junit4:junit4]   2> 3733 T1766 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1363725865648/'
[junit4:junit4]   2> 3733 T1766 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1363725865648/'
[junit4:junit4]   2> 3749 T1766 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 3750 T1766 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 3750 T1766 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 3750 T1766 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 3751 T1766 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 3751 T1766 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 3751 T1766 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 3752 T1766 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 3752 T1766 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 3752 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 3758 T1766 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 3767 T1766 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:40338/solr
[junit4:junit4]   2> 3767 T1766 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 3767 T1766 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:40338 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@7e5220e4
[junit4:junit4]   2> 3768 T1766 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3769 T1845 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:40338. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 3769 T1845 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:40338, initiating session
[junit4:junit4]   2> 3769 T1768 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:55552
[junit4:junit4]   2> 3769 T1768 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:55552
[junit4:junit4]   2> 3770 T1770 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d84654469000b with negotiated timeout 20000 for client /127.0.0.1:55552
[junit4:junit4]   2> 3770 T1845 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:40338, sessionid = 0x13d84654469000b, negotiated timeout = 20000
[junit4:junit4]   2> 3770 T1846 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7e5220e4 name:ZooKeeperConnection Watcher:127.0.0.1:40338 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3770 T1766 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3772 T1771 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d84654469000b
[junit4:junit4]   2> 3772 T1846 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 3772 T1768 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:55552 which had sessionid 0x13d84654469000b
[junit4:junit4]   2> 3772 T1766 oaz.ZooKeeper.close Session: 0x13d84654469000b closed
[junit4:junit4]   2> 3773 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 3775 T1766 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:40338/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@54185d95
[junit4:junit4]   2> 3776 T1766 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3776 T1847 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:40338. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 3776 T1847 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:40338, initiating session
[junit4:junit4]   2> 3776 T1768 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:55553
[junit4:junit4]   2> 3777 T1768 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:55553
[junit4:junit4]   2> 3778 T1770 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d84654469000c with negotiated timeout 20000 for client /127.0.0.1:55553
[junit4:junit4]   2> 3778 T1847 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:40338, sessionid = 0x13d84654469000c, negotiated timeout = 20000
[junit4:junit4]   2> 3778 T1848 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@54185d95 name:ZooKeeperConnection Watcher:127.0.0.1:40338/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3778 T1766 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3780 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d84654469000c type:create cxid:0x1 zxid:0x48 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3781 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d84654469000c type:create cxid:0x3 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3782 T1766 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4784 T1766 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51404_x_oin%2Fu
[junit4:junit4]   2> 4785 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d84654469000c type:delete cxid:0xd zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:51404_x_oin%2Fu Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:51404_x_oin%2Fu
[junit4:junit4]   2> 4786 T1766 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51404_x_oin%2Fu
[junit4:junit4]   2> 4788 T1793 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 4788 T1788 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 4788 T1820 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 4788 T1834 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 4788 T1806 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 4788 T1848 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 4792 T1766 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 4792 T1766 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 4793 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 4795 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 4798 T1800 oasc.CoreContainer.create Creating SolrCore 'unloadcollection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1363725862279/unloadcollection1
[junit4:junit4]   2> 4799 T1800 oasc.ZkController.createCollectionZkNode Check for collection zkNode:unloadcollection
[junit4:junit4]   2> 4799 T1800 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:unloadcollection
[junit4:junit4]   2> 4800 T1800 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4]   2> 4800 T1800 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4]   2> 4801 T1800 oascc.SolrZkClient.makePath makePath: /collections/unloadcollection
[junit4:junit4]   2> 4802 T1800 oasc.ZkController.readConfigName Load collection config from:/collections/unloadcollection
[junit4:junit4]   2> 4803 T1800 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1363725862279/unloadcollection1/'
[junit4:junit4]   2> 4834 T1800 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 4861 T1800 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 4862 T1800 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 4866 T1800 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 5139 T1800 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 5144 T1800 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 5146 T1800 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 5156 T1800 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5159 T1800 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5162 T1800 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5163 T1800 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 5163 T1800 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 5163 T1800 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5165 T1800 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 5165 T1800 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 5165 T1800 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 5165 T1800 oasc.SolrCore.<init> [unloadcollection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1363725862279/unloadcollection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725866783unloadcollection1_1n/
[junit4:junit4]   2> 5166 T1800 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5e7ce905
[junit4:junit4]   2> 5167 T1800 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 5168 T1800 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725866783unloadcollection1_1n forceNew: false
[junit4:junit4]   2> 5168 T1800 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725866783unloadcollection1_1n/index/
[junit4:junit4]   2> 5168 T1800 oasc.SolrCore.initIndex WARNING [unloadcollection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725866783unloadcollection1_1n/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 5168 T1800 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725866783unloadcollection1_1n/index forceNew: false
[junit4:junit4]   2> 5170 T1800 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@7f076627 lockFactory=org.apache.lucene.store.NativeFSLockFactory@57b0fe9a; maxCacheMB=0.896484375 maxMergeSizeMB=0.7900390625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 5170 T1800 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 5172 T1800 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 5172 T1800 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 5172 T1800 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 5173 T1800 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 5173 T1800 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 5173 T1800 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 5174 T1800 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 5174 T1800 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 5174 T1800 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 5177 T1800 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 5179 T1800 oass.SolrIndexSearcher.<init> Opening Searcher@a7fdf19 main
[junit4:junit4]   2> 5179 T1800 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725866783unloadcollection1_1n/tlog
[junit4:junit4]   2> 5180 T1800 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 5180 T1800 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 5182 T1850 oasc.SolrCore.registerSearcher [unloadcollection1] Registered new searcher Searcher@a7fdf19 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 5183 T1800 oasc.ZkController.publish publishing core=unloadcollection1 state=down
[junit4:junit4]   2> 6292 T1789 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6293 T1789 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"unloadcollection1",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "collection":"unloadcollection",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53441_x_oin%2Fu",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53441/x_oin/u"}
[junit4:junit4]   2> 6293 T1789 oasc.Overseer$ClusterStateUpdater.createCollection Create collection unloadcollection with numShards 1
[junit4:junit4]   2> 6293 T1789 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 6297 T1820 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 6297 T1788 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 6297 T1793 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 6297 T1806 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 6297 T1848 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 6297 T1834 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 7185 T1800 oasc.CoreContainer.registerCore registering core: unloadcollection1
[junit4:junit4]   2> 7185 T1800 oasc.ZkController.register Register replica - core:unloadcollection1 address:http://127.0.0.1:53441/x_oin/u collection:unloadcollection shard:shard1
[junit4:junit4]   2> 7186 T1800 oascc.SolrZkClient.makePath makePath: /collections/unloadcollection/leader_elect/shard1/election
[junit4:junit4]   2> 7193 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d846544690006 type:delete cxid:0x51 zxid:0x57 txntype:-1 reqpath:n/a Error Path:/solr/collections/unloadcollection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/unloadcollection/leaders
[junit4:junit4]   2> 7194 T1800 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 7194 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d846544690006 type:create cxid:0x52 zxid:0x58 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7196 T1800 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 7196 T1800 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 7197 T1800 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53441/x_oin/u/unloadcollection1/
[junit4:junit4]   2> 7197 T1800 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 7197 T1800 oasc.SyncStrategy.syncToMe http://127.0.0.1:53441/x_oin/u/unloadcollection1/ has no replicas
[junit4:junit4]   2> 7197 T1800 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53441/x_oin/u/unloadcollection1/
[junit4:junit4]   2> 7198 T1800 oascc.SolrZkClient.makePath makePath: /collections/unloadcollection/leaders/shard1
[junit4:junit4]   2> 7202 T1771 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d846544690006 type:create cxid:0x5d zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7801 T1789 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7807 T1848 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 7807 T1834 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 7807 T1820 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 7808 T1806 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 7808 T1788 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 7807 T1793 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 7855 T1800 oasc.ZkController.register We are http://127.0.0.1:53441/x_oin/u/unloadcollection1/ and leader is http://127.0.0.1:53441/x_oin/u/unloadcollection1/
[junit4:junit4]   2> 7855 T1800 oasc.ZkController.register No LogReplay needed for core=unloadcollection1 baseURL=http://127.0.0.1:53441/x_oin/u
[junit4:junit4]   2> 7855 T1800 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 7856 T1800 oasc.ZkController.publish publishing core=unloadcollection1 state=active
[junit4:junit4]   2> 7858 T1800 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7858 T1800 oasc.CoreContainer.persistFile Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1363725862279/solr.xml
[junit4:junit4]   2> 7863 T1800 oasc.SolrXMLSerializer.persistFile Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1363725862279/solr.xml
[junit4:junit4]   2> 7865 T1800 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {wt=javabin&version=2&dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725866783unloadcollection1_1n&collection=unloadcollection&numShards=1&name=unloadcollection1&action=CREATE} status=0 QTime=3067 
[junit4:junit4]   2> 7865 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 7866 T1766 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:40338/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@7854bd3f
[junit4:junit4]   2> 7867 T1766 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 7867 T1851 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:40338. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 7868 T1851 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:40338, initiating session
[junit4:junit4]   2> 7868 T1768 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:55555
[junit4:junit4]   2> 7868 T1768 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:55555
[junit4:junit4]   2> 7869 T1770 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d84654469000d with negotiated timeout 10000 for client /127.0.0.1:55555
[junit4:junit4]   2> 7869 T1851 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:40338, sessionid = 0x13d84654469000d, negotiated timeout = 10000
[junit4:junit4]   2> 7869 T1852 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7854bd3f name:ZooKeeperConnection Watcher:127.0.0.1:40338/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 7869 T1766 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 7872 T1766 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 7877 T1766 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7878 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 7883 T1814 oasc.CoreContainer.create Creating SolrCore 'unloadcollection2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1363725863396/unloadcollection2
[junit4:junit4]   2> 7883 T1814 oasc.ZkController.createCollectionZkNode Check for collection zkNode:unloadcollection
[junit4:junit4]   2> 7884 T1814 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 7884 T1814 oasc.ZkController.readConfigName Load collection config from:/collections/unloadcollection
[junit4:junit4]   2> 7885 T1814 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1363725863396/unloadcollection2/'
[junit4:junit4]   2> 7913 T1814 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 7939 T1814 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 7940 T1814 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 7943 T1814 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 8217 T1814 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 8221 T1814 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 8223 T1814 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 8235 T1814 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8238 T1814 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8240 T1814 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8242 T1814 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 8243 T1814 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 8243 T1814 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8244 T1814 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 8245 T1814 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 8245 T1814 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 8245 T1814 oasc.SolrCore.<init> [unloadcollection2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1363725863396/unloadcollection2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725869868unloadcollection1_2n/
[junit4:junit4]   2> 8246 T1814 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5e7ce905
[junit4:junit4]   2> 8246 T1814 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 8246 T1814 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725869868unloadcollection1_2n forceNew: false
[junit4:junit4]   2> 8247 T1814 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725869868unloadcollection1_2n/index/
[junit4:junit4]   2> 8247 T1814 oasc.SolrCore.initIndex WARNING [unloadcollection2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725869868unloadcollection1_2n/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 8247 T1814 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725869868unloadcollection1_2n/index forceNew: false
[junit4:junit4]   2> 8249 T1814 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@40fe5cf7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3cf6a996; maxCacheMB=0.896484375 maxMergeSizeMB=0.7900390625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 8249 T1814 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 8250 T1814 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 8250 T1814 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 8251 T1814 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 8251 T1814 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 8252 T1814 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 8252 T1814 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 8252 T1814 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 8252 T1814 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 8253 T1814 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 8255 T1814 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 8257 T1814 oass.SolrIndexSearcher.<init> Opening Searcher@7a641382 main
[junit4:junit4]   2> 8257 T1814 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725869868unloadcollection1_2n/tlog
[junit4:junit4]   2> 8258 T1814 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 8258 T1814 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 8261 T1853 oasc.SolrCore.registerSearcher [unloadcollection2] Registered new searcher Searcher@7a641382 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 8262 T1814 oasc.ZkController.publish publishing core=unloadcollection2 state=down
[junit4:junit4]   2> 8262 T1814 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 9313 T1789 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9314 T1789 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"unloadcollection1",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:53441_x_oin%2Fu_unloadcollection1",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "collection":"unloadcollection",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53441_x_oin%2Fu",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53441/x_oin/u"}
[junit4:junit4]   2> 9318 T1789 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"unloadcollection2",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "collection":"unloadcollection",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:42905_x_oin%2Fu",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:42905/x_oin/u"}
[junit4:junit4]   2> 9318 T1789 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4]   2> 9318 T1789 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 9322 T1793 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 9322 T1834 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 9322 T1806 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 9322 T1788 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 9322 T1820 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 9322 T1848 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 9322 T1852 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 10264 T1814 oasc.CoreContainer.registerCore registering core: unloadcollection2
[junit4:junit4]   2> 10264 T1814 oasc.ZkController.register Register replica - core:unloadcollection2 address:http://127.0.0.1:42905/x_oin/u collection:unloadcollection shard:shard1
[junit4:junit4]   2> 10267 T1814 oasc.ZkController.register We are http://127.0.0.1:42905/x_oin/u/unloadcollection2/ and leader is http://127.0.0.1:53441/x_oin/u/unloadcollection1/
[junit4:junit4]   2> 10267 T1814 oasc.ZkController.register No LogReplay needed for core=unloadcollection2 baseURL=http://127.0.0.1:42905/x_oin/u
[junit4:junit4]   2> 10267 T1814 oasc.ZkController.checkRecovery Core needs to recover:unloadcollection2
[junit4:junit4]   2> 10268 T1814 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C138 name=unloadcollection2 org.apache.solr.core.SolrCore@36ebd65d url=http://127.0.0.1:42905/x_oin/u/unloadcollection2 node=127.0.0.1:42905_x_oin%2Fu C138_STATE=coll:unloadcollection core:unloadcollection2 props:{core=unloadcollection2, state=down, collection=unloadcollection, node_name=127.0.0.1:42905_x_oin%2Fu, base_url=http://127.0.0.1:42905/x_oin/u}
[junit4:junit4]   2> 10268 T1854 C138 P42905 oasc.RecoveryStrategy.run Starting recovery process.  core=unloadcollection2 recoveringAfterStartup=true
[junit4:junit4]   2> 10269 T1854 C138 P42905 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 10269 T1814 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10269 T1854 C138 P42905 oasc.ZkController.publish publishing core=unloadcollection2 state=recovering
[junit4:junit4]   2> 10270 T1854 C138 P42905 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 10270 T1814 oasc.CoreContainer.persistFile Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1363725863396/solr.xml
[junit4:junit4]   2> 10271 T1854 C138 P42905 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 10274 T1814 oasc.SolrXMLSerializer.persistFile Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1363725863396/solr.xml
[junit4:junit4]   2> 10275 T1814 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {wt=javabin&version=2&dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725869868unloadcollection1_2n&collection=unloadcollection&name=unloadcollection2&action=CREATE} status=0 QTime=2392 
[junit4:junit4]   2> 10276 T1766 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10277 T1766 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: unloadcollection failOnTimeout:true timeout (sec):230
[junit4:junit4]   2> 10278 T1766 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10828 T1789 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10829 T1789 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"unloadcollection2",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:42905_x_oin%2Fu_unloadcollection2",
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "collection":"unloadcollection",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:42905_x_oin%2Fu",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:42905/x_oin/u"}
[junit4:junit4]   2> 10847 T1820 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 10847 T1793 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 10847 T1834 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 10847 T1848 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 10847 T1852 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 10847 T1788 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 10848 T1806 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 11275 T1802 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {wt=javabin&onlyIfLeader=true&coreNodeName=127.0.0.1:42905_x_oin%252Fu_unloadcollection2&nodeName=127.0.0.1:42905_x_oin%252Fu&checkLive=true&core=unloadcollection1&version=2&state=recovering&action=PREPRECOVERY} status=0 QTime=1001 
[junit4:junit4]   2> 11279 T1766 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12281 T1766 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C138_STATE=coll:unloadcollection core:unloadcollection2 props:{core=unloadcollection2, state=recovering, collection=unloadcollection, shard=shard1, node_name=127.0.0.1:42905_x_oin%2Fu, base_url=http://127.0.0.1:42905/x_oin/u}
[junit4:junit4]   2> 13276 T1854 C138 P42905 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:53441/x_oin/u/unloadcollection1/ core=unloadcollection2 - recoveringAfterStartup=true
[junit4:junit4]   2> 13277 T1854 C138 P42905 oasu.PeerSync.sync PeerSync: core=unloadcollection2 url=http://127.0.0.1:42905/x_oin/u START replicas=[http://127.0.0.1:53441/x_oin/u/unloadcollection1/] nUpdates=100
[junit4:junit4]   2> 13277 T1854 C138 P42905 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 13277 T1854 C138 P42905 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=unloadcollection2
[junit4:junit4]   2> 13277 T1854 C138 P42905 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=unloadcollection2
[junit4:junit4]   2> 13277 T1854 C138 P42905 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=unloadcollection2
[junit4:junit4]   2> 13277 T1854 C138 P42905 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 13278 T1854 C138 P42905 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:53441/x_oin/u/unloadcollection1/. core=unloadcollection2
[junit4:junit4]   2> 13278 T1854 C138 P42905 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 13288 T1766 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> ASYNC  NEW_CORE C139 name=unloadcollection1 org.apache.solr.core.SolrCore@1018eef3 url=http://127.0.0.1:53441/x_oin/u/unloadcollection1 node=127.0.0.1:53441_x_oin%2Fu C139_STATE=coll:unloadcollection core:unloadcollection1 props:{core=unloadcollection1, state=active, collection=unloadcollection, shard=shard1, node_name=127.0.0.1:53441_x_oin%2Fu, base_url=http://127.0.0.1:53441/x_oin/u, leader=true}
[junit4:junit4]   2> 13289 T1799 C139 P53441 REQ /get {wt=javabin&getVersions=100&qt=/get&version=2&distrib=false} status=0 QTime=0 
[junit4:junit4]   2> 13290 T1802 C139 P53441 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 13292 T1802 C139 P53441 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@7f076627 lockFactory=org.apache.lucene.store.NativeFSLockFactory@57b0fe9a; maxCacheMB=0.896484375 maxMergeSizeMB=0.7900390625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 13292 T1802 C139 P53441 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 13293 T1802 C139 P53441 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@7f076627 lockFactory=org.apache.lucene.store.NativeFSLockFactory@57b0fe9a; maxCacheMB=0.896484375 maxMergeSizeMB=0.7900390625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@7f076627 lockFactory=org.apache.lucene.store.NativeFSLockFactory@57b0fe9a; maxCacheMB=0.896484375 maxMergeSizeMB=0.7900390625)),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 13293 T1802 C139 P53441 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 13293 T1802 C139 P53441 oass.SolrIndexSearcher.<init> Opening Searcher@7986582 realtime
[junit4:junit4]   2> 13294 T1802 C139 P53441 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 13294 T1802 C139 P53441 /update {wt=javabin&commit=true&openSearcher=false&version=2&softCommit=false&commit_end_point=true&waitSearcher=true} {commit=} 0 4
[junit4:junit4]   2> 13295 T1854 C138 P42905 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 13295 T1854 C138 P42905 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 13298 T1801 C139 P53441 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 13299 T1801 C139 P53441 REQ /replication {qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=3 
[junit4:junit4]   2> 13299 T1854 C138 P42905 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 13299 T1854 C138 P42905 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 13299 T1854 C138 P42905 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 13301 T1799 C139 P53441 REQ /replication {qt=/replication&wt=javabin&version=2&command=filelist&generation=2} status=0 QTime=0 
[junit4:junit4]   2> 13302 T1854 C138 P42905 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 13302 T1854 C138 P42905 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725869868unloadcollection1_2n/index.20130320084435288 forceNew: false
[junit4:junit4]   2> 13303 T1854 C138 P42905 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@52d6eaf4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3eb20b9)) fullCopy=false
[junit4:junit4]   2> 13305 T1802 C139 P53441 REQ /replication {wt=filestream&qt=/replication&file=segments_2&checksum=true&command=filecontent&generation=2} status=0 QTime=0 
[junit4:junit4]   2> 13306 T1854 C138 P42905 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 13306 T1854 C138 P42905 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 13306 T1854 C138 P42905 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=unloadcollection2
[junit4:junit4]   2> 13307 T1854 C138 P42905 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@40fe5cf7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3cf6a996; maxCacheMB=0.896484375 maxMergeSizeMB=0.7900390625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@40fe5cf7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3cf6a996; maxCacheMB=0.896484375 maxMergeSizeMB=0.7900390625)),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 13308 T1854 C138 P42905 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 13308 T1854 C138 P42905 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 13308 T1854 C138 P42905 oass.SolrIndexSearcher.<init> Opening Searcher@241bdfd8 main
[junit4:junit4]   2> 13309 T1853 oasc.SolrCore.registerSearcher [unloadcollection2] Registered new searcher Searcher@241bdfd8 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 13309 T1854 C138 P42905 oasc.RecoveryStrategy.replay No replay needed. core=unloadcollection2
[junit4:junit4]   2> 13309 T1854 C138 P42905 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=unloadcollection2
[junit4:junit4]   2> 13309 T1854 C138 P42905 oasc.ZkController.publish publishing core=unloadcollection2 state=active
[junit4:junit4]   2> 13309 T1854 C138 P42905 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 13311 T1854 C138 P42905 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=unloadcollection2
[junit4:junit4]   2> 13856 T1789 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13857 T1789 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"unloadcollection2",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:42905_x_oin%2Fu_unloadcollection2",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "collection":"unloadcollection",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:42905_x_oin%2Fu",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:42905/x_oin/u"}
[junit4:junit4]   2> 13860 T1806 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 13860 T1848 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 13860 T1834 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 13861 T1852 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 13860 T1788 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 13860 T1793 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 13861 T1820 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 14291 T1766 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14293 T1766 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: unloadcollection
[junit4:junit4]   2> 14294 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2>  C138_STATE=coll:unloadcollection core:unloadcollection2 props:{core=unloadcollection2, state=active, collection=unloadcollection, shard=shard1, node_name=127.0.0.1:42905_x_oin%2Fu, base_url=http://127.0.0.1:42905/x_oin/u}
[junit4:junit4]   2> 14308 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[6 (1429970224452468736)]} 0 1
[junit4:junit4]   2> 14309 T1802 C139 P53441 /update {wt=javabin&version=2} {add=[6 (1429970224452468736)]} 0 9
[junit4:junit4]   2> 14316 T1813 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[7 (1429970224465051648)]} 0 2
[junit4:junit4]   2> 14316 T1800 C139 P53441 /update {wt=javabin&version=2} {add=[7 (1429970224465051648)]} 0 4
[junit4:junit4]   2> 14322 T1814 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[8 (1429970224472391680)]} 0 1
[junit4:junit4]   2> 14322 T1801 C139 P53441 /update {wt=javabin&version=2} {add=[8 (1429970224472391680)]} 0 3
[junit4:junit4]   2> 14324 T1799 C139 P53441 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 14328 T1799 C139 P53441 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@7f076627 lockFactory=org.apache.lucene.store.NativeFSLockFactory@57b0fe9a; maxCacheMB=0.896484375 maxMergeSizeMB=0.7900390625)),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@7f076627 lockFactory=org.apache.lucene.store.NativeFSLockFactory@57b0fe9a; maxCacheMB=0.896484375 maxMergeSizeMB=0.7900390625)),segFN=segments_3,generation=3,filenames=[_0.si, _0.fdx, _0.cbnd, _0.tip, _0.fnm, _0.tim, _0.doc, _0.fdt, _0.dvdm, segments_3, _0.cbnm, _0.pos, _0.dvdd]
[junit4:junit4]   2> 14328 T1799 C139 P53441 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0.si, _0.fdx, _0.cbnd, _0.tip, _0.fnm, _0.tim, _0.doc, _0.fdt, _0.dvdm, segments_3, _0.cbnm, _0.pos, _0.dvdd]
[junit4:junit4]   2> 14329 T1799 C139 P53441 oass.SolrIndexSearcher.<init> Opening Searcher@69a687d8 main
[junit4:junit4]   2> 14329 T1799 C139 P53441 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 14330 T1850 oasc.SolrCore.registerSearcher [unloadcollection1] Registered new searcher Searcher@69a687d8 main{StandardDirectoryReader(segments_3:3:nrt _0(5.0):C3)}
[junit4:junit4]   2> 14330 T1799 C139 P53441 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:42905/x_oin/u/unloadcollection2/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4]   2> 14332 T1815 C138 P42905 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 14335 T1815 C138 P42905 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@40fe5cf7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3cf6a996; maxCacheMB=0.896484375 maxMergeSizeMB=0.7900390625)),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@40fe5cf7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3cf6a996; maxCacheMB=0.896484375 maxMergeSizeMB=0.7900390625)),segFN=segments_3,generation=3,filenames=[_0.si, _0.fdx, _0.cbnd, _0.tip, _0.fnm, _0.tim, _0.doc, _0.fdt, _0.dvdm, segments_3, _0.cbnm, _0.pos, _0.dvdd]
[junit4:junit4]   2> 14335 T1815 C138 P42905 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0.si, _0.fdx, _0.cbnd, _0.tip, _0.fnm, _0.tim, _0.doc, _0.fdt, _0.dvdm, segments_3, _0.cbnm, _0.pos, _0.dvdd]
[junit4:junit4]   2> 14336 T1815 C138 P42905 oass.SolrIndexSearcher.<init> Opening Searcher@7ab5e4a2 main
[junit4:junit4]   2> 14337 T1815 C138 P42905 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 14337 T1853 oasc.SolrCore.registerSearcher [unloadcollection2] Registered new searcher Searcher@7ab5e4a2 main{StandardDirectoryReader(segments_3:3:nrt _0(5.0):C3)}
[junit4:junit4]   2> 14338 T1815 C138 P42905 /update {wt=javabin&commit=true&version=2&expungeDeletes=false&softCommit=false&commit_end_point=true&waitSearcher=true} {commit=} 0 6
[junit4:junit4]   2> 14338 T1799 C139 P53441 /update {wt=javabin&commit=true&version=2&softCommit=false&waitSearcher=true} {commit=} 0 14
[junit4:junit4]   2> 14339 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 14342 T1830 oasc.CoreContainer.create Creating SolrCore 'unloadcollection3' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1363725864516/unloadcollection3
[junit4:junit4]   2> 14343 T1830 oasc.ZkController.createCollectionZkNode Check for collection zkNode:unloadcollection
[junit4:junit4]   2> 14344 T1830 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 14344 T1830 oasc.ZkController.readConfigName Load collection config from:/collections/unloadcollection
[junit4:junit4]   2> 14345 T1830 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1363725864516/unloadcollection3/'
[junit4:junit4]   2> 14380 T1830 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 14420 T1830 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 14421 T1830 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 14427 T1830 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 14722 T1830 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 14728 T1830 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 14732 T1830 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 14744 T1830 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14748 T1830 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14752 T1830 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14753 T1830 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 14753 T1830 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 14754 T1830 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14755 T1830 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 14755 T1830 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 14756 T1830 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 14756 T1830 oasc.SolrCore.<init> [unloadcollection3] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1363725864516/unloadcollection3/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725876327unloadcollection_3n/
[junit4:junit4]   2> 14756 T1830 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5e7ce905
[junit4:junit4]   2> 14757 T1830 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 14758 T1830 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725876327unloadcollection_3n forceNew: false
[junit4:junit4]   2> 14758 T1830 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725876327unloadcollection_3n/index/
[junit4:junit4]   2> 14758 T1830 oasc.SolrCore.initIndex WARNING [unloadcollection3] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725876327unloadcollection_3n/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 14759 T1830 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725876327unloadcollection_3n/index forceNew: false
[junit4:junit4]   2> 14761 T1830 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4e9e1063 lockFactory=org.apache.lucene.store.NativeFSLockFactory@20e0a12f; maxCacheMB=0.896484375 maxMergeSizeMB=0.7900390625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 14762 T1830 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 14764 T1830 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 14764 T1830 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 14765 T1830 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 14765 T1830 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 14766 T1830 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 14766 T1830 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 14767 T1830 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 14767 T1830 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 14768 T1830 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 14771 T1830 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 14774 T1830 oass.SolrIndexSearcher.<init> Opening Searcher@48a56030 main
[junit4:junit4]   2> 14775 T1830 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725876327unloadcollection_3n/tlog
[junit4:junit4]   2> 14775 T1830 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 14776 T1830 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 14779 T1858 oasc.SolrCore.registerSearcher [unloadcollection3] Registered new searcher Searcher@48a56030 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 14779 T1830 oasc.ZkController.publish publishing core=unloadcollection3 state=down
[junit4:junit4]   2> 14780 T1830 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 15366 T1789 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15366 T1789 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"unloadcollection3",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "collection":"unloadcollection",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:45397_x_oin%2Fu",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:45397/x_oin/u"}
[junit4:junit4]   2> 15367 T1789 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4]   2> 15367 T1789 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 15370 T1788 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 15370 T1834 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 15370 T1806 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 15370 T1848 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 15370 T1852 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 15370 T1793 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 15370 T1820 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 15781 T1830 oasc.CoreContainer.registerCore registering core: unloadcollection3
[junit4:junit4]   2> 15781 T1830 oasc.ZkController.register Register replica - core:unloadcollection3 address:http://127.0.0.1:45397/x_oin/u collection:unloadcollection shard:shard1
[junit4:junit4]   2> 15785 T1830 oasc.ZkController.register We are http://127.0.0.1:45397/x_oin/u/unloadcollection3/ and leader is http://127.0.0.1:53441/x_oin/u/unloadcollection1/
[junit4:junit4]   2> 15785 T1830 oasc.ZkController.register No LogReplay needed for core=unloadcollection3 baseURL=http://127.0.0.1:45397/x_oin/u
[junit4:junit4]   2> 15785 T1830 oasc.ZkController.checkRecovery Core needs to recover:unloadcollection3
[junit4:junit4]   2> 15786 T1830 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C140 name=unloadcollection3 org.apache.solr.core.SolrCore@1dcfd646 url=http://127.0.0.1:45397/x_oin/u/unloadcollection3 node=127.0.0.1:45397_x_oin%2Fu C140_STATE=coll:unloadcollection core:unloadcollection3 props:{core=unloadcollection3, state=down, collection=unloadcollection, node_name=127.0.0.1:45397_x_oin%2Fu, base_url=http://127.0.0.1:45397/x_oin/u}
[junit4:junit4]   2> 15786 T1859 C140 P45397 oasc.RecoveryStrategy.run Starting recovery process.  core=unloadcollection3 recoveringAfterStartup=true
[junit4:junit4]   2> 15787 T1859 C140 P45397 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 15786 T1830 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15787 T1859 C140 P45397 oasc.ZkController.publish publishing core=unloadcollection3 state=recovering
[junit4:junit4]   2> 15788 T1859 C140 P45397 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 15788 T1830 oasc.CoreContainer.persistFile Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1363725864516/solr.xml
[junit4:junit4]   2> 15789 T1859 C140 P45397 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 15793 T1830 oasc.SolrXMLSerializer.persistFile Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1363725864516/solr.xml
[junit4:junit4]   2> 15794 T1830 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {wt=javabin&version=2&dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725876327unloadcollection_3n&collection=unloadcollection&name=unloadcollection3&action=CREATE} status=0 QTime=1452 
[junit4:junit4]   2> 15794 T1766 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: unloadcollection failOnTimeout:true timeout (sec):230
[junit4:junit4]   2> 15795 T1766 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16797 T1766 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16874 T1789 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16875 T1789 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"unloadcollection3",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:45397_x_oin%2Fu_unloadcollection3",
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "collection":"unloadcollection",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:45397_x_oin%2Fu",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:45397/x_oin/u"}
[junit4:junit4]   2> 16878 T1788 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 16878 T1820 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 16878 T1793 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 16878 T1834 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 16879 T1848 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 16879 T1806 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 16878 T1852 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 17793 T1801 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {wt=javabin&onlyIfLeader=true&coreNodeName=127.0.0.1:45397_x_oin%252Fu_unloadcollection3&nodeName=127.0.0.1:45397_x_oin%252Fu&checkLive=true&core=unloadcollection1&version=2&state=recovering&action=PREPRECOVERY} status=0 QTime=2000 
[junit4:junit4]   2> 17798 T1766 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18800 T1766 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C140_STATE=coll:unloadcollection core:unloadcollection3 props:{core=unloadcollection3, state=recovering, collection=unloadcollection, shard=shard1, node_name=127.0.0.1:45397_x_oin%2Fu, base_url=http://127.0.0.1:45397/x_oin/u}
[junit4:junit4]   2> 19794 T1859 C140 P45397 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:53441/x_oin/u/unloadcollection1/ core=unloadcollection3 - recoveringAfterStartup=true
[junit4:junit4]   2> 19794 T1859 C140 P45397 oasu.PeerSync.sync PeerSync: core=unloadcollection3 url=http://127.0.0.1:45397/x_oin/u START replicas=[http://127.0.0.1:53441/x_oin/u/unloadcollection1/] nUpdates=100
[junit4:junit4]   2> 19795 T1859 C140 P45397 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 19795 T1859 C140 P45397 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=unloadcollection3
[junit4:junit4]   2> 19795 T1859 C140 P45397 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=unloadcollection3
[junit4:junit4]   2> 19795 T1859 C140 P45397 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=unloadcollection3
[junit4:junit4]   2> 19795 T1859 C140 P45397 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 19796 T1859 C140 P45397 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:53441/x_oin/u/unloadcollection1/. core=unloadcollection3
[junit4:junit4]   2> 19796 T1859 C140 P45397 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 19797 T1800 C139 P53441 REQ /get {wt=javabin&getVersions=100&qt=/get&version=2&distrib=false} status=0 QTime=0 
[junit4:junit4]   2> 19801 T1799 C139 P53441 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 19802 T1799 C139 P53441 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=3
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@7f076627 lockFactory=org.apache.lucene.store.NativeFSLockFactory@57b0fe9a; maxCacheMB=0.896484375 maxMergeSizeMB=0.7900390625)),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@7f076627 lockFactory=org.apache.lucene.store.NativeFSLockFactory@57b0fe9a; maxCacheMB=0.896484375 maxMergeSizeMB=0.7900390625)),segFN=segments_3,generation=3,filenames=[_0.si, _0.fdx, _0.cbnd, _0.tip, _0.fnm, _0.tim, _0.doc, _0.fdt, _0.dvdm, segments_3, _0.cbnm, _0.pos, _0.dvdd]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@7f076627 lockFactory=org.apache.lucene.store.NativeFSLockFactory@57b0fe9a; maxCacheMB=0.896484375 maxMergeSizeMB=0.7900390625)),segFN=segments_4,generation=4,filenames=[_0.si, _0.fdx, _0.cbnd, _0.tip, _0.fnm, _0.tim, _0.doc, _0.fdt, _0.dvdm, _0.cbnm, segments_4, _0.pos, _0.dvdd]
[junit4:junit4]   2> 19802 T1766 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19802 T1799 C139 P53441 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[_0.si, _0.fdx, _0.cbnd, _0.tip, _0.fnm, _0.tim, _0.doc, _0.fdt, _0.dvdm, _0.cbnm, segments_4, _0.pos, _0.dvdd]
[junit4:junit4]   2> 19803 T1799 C139 P53441 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 19803 T1799 C139 P53441 /update {wt=javabin&commit=true&openSearcher=false&version=2&softCommit=false&commit_end_point=true&waitSearcher=true} {commit=} 0 2
[junit4:junit4]   2> 19803 T1859 C140 P45397 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 19804 T1859 C140 P45397 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 19806 T1801 C139 P53441 REQ /replication {qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 
[junit4:junit4]   2> 19806 T1859 C140 P45397 oash.SnapPuller.fetchLatestIndex Master's generation: 4
[junit4:junit4]   2> 19806 T1859 C140 P45397 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 19806 T1859 C140 P45397 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 19808 T1800 C139 P53441 REQ /replication {qt=/replication&wt=javabin&version=2&command=filelist&generation=4} status=0 QTime=0 
[junit4:junit4]   2> 19809 T1859 C140 P45397 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 13
[junit4:junit4]   2> 19810 T1859 C140 P45397 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1363725861990/1363725876327unloadcollection_3n/index.20130320084441795 forceNew: false
[junit4:junit4]   2> 19810 T1859 C140 P45397 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@25cda3bd lockFactory=org.apache.lucene.store.NativeFSLockFactory@6f0a937e)) fullCopy=false
[junit4:junit4]   2> 19813 T1799 C139 P53441 REQ /replication {wt=filestream&qt=/replication&file=_0.si&checksum=true&command=filecontent&generation=4} status=0 QTime=1 
[junit4:junit4]   2> 19816 T1802 C139 P53441 REQ /replication {wt=filestream&qt=/replication&file=_0.fdx&checksum=true&command=filecontent&generation=4} status=0 QTime=0 
[junit4:junit4]   2> 19819 T1801 C139 P53441 REQ /replication {wt=filestream&qt=/replication&file=_0.cbnd&checksum=true&command=filecontent&generation=4} status=0 QTime=1 
[junit4:junit4]   2> 19821 T1800 C139 P53441 REQ /replication {wt=filestream&qt=/replication&file=_0.tip&checksum=true&command=filecontent&generation=4} status=0 QTime=0 
[junit4:junit4]   2> 19824 T1799 C139 P53441 REQ /replication {wt=filestream&qt=/replication&file=_0.fnm&checksum=true&command=filecontent&generation=4} status=0 QTime=0 
[junit4:junit4]   2> 19827 T1802 C139 P53441 REQ /replication {wt=filestream&qt=/replication&file=_0.tim&checksum=true&command=filecontent&generation=4} status=0 QTime=0 
[junit4:junit4]   2> 19830 T1801 C139 P53441 REQ /replication {wt=filestream&qt=/replication&file=_0.doc&checksum=true&command=filecontent&generation=4} status=0 QTime=0 
[junit4:junit4]   2> 19833 T1800 C139 P53441 REQ /replication {wt=filestream&qt=/replication&file=_0.fdt&checksum=true&command=filecontent&generation=4} status=0 QTime=0 
[junit4:junit4]   2> 19836 T1799 C139 P53441 REQ /replication {wt=filestream&qt=/replication&file=_0.dvdm&checksum=true&command=filecontent&generation=4} status=0 QTime=0 
[junit4:junit4]   2> 19838 T1802 C139 P53441 REQ /replication {wt=filestream&qt=/replication&file=_0.cbnm&checksum=true&command=filecontent&generation=4} status=0 QTime=0 
[junit4:junit4]   2> 19841 T1801 C139 P53441 REQ /replication {wt=filestream&qt=/replication&file=_0.pos&checksum=true&command=filecontent&generation=4} status=0 QTime=0 
[junit4:junit4]   2> 19844 T1800 C139 P53441 REQ /replication {wt=filestream&qt=/replication&file=segments_4&checksum=true&command=filecontent&generation=4} status=0 QTime=1 
[junit4:junit4]   2> 19846 T1799 C139 P53441 REQ /replication {wt=filestream&qt=/replication&file=_0.dvdd&checksum=true&command=filecontent&generation=4} status=0 QTime=0 
[junit4:junit4]   2> 19847 T1859 C140 P45397 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 19848 T1859 C140 P45397 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 19848 T1859 C140 P45397 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=unloadcollection3
[junit4:junit4]   2> 19849 T1859 C140 P45397 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4e9e1063 lockFactory=org.apache.lucene.store.NativeFSLockFactory@20e0a12f; maxCacheMB=0.896484375 maxMergeSizeMB=0.7900390625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4e9e1063 lockFactory=org.apache.lucene.store.NativeFSLockFactory@20e0a12f; maxCacheMB=0.896484375 maxMergeSizeMB=0.7900390625)),segFN=segments_4,generation=4,filenames=[_0.si, _0.fdx, _0.cbnd, _0.tip, _0.fnm, _0.tim, _0.doc, _0.fdt, _0.dvdm, _0.cbnm, segments_4, _0.pos, _0.dvdd]
[junit4:junit4]   2> 19849 T1859 C140 P45397 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[_0.si, _0.fdx, _0.cbnd, _0.tip, _0.fnm, _0.tim, _0.doc, _0.fdt, _0.dvdm, _0.cbnm, segments_4, _0.pos, _0.dvdd]
[junit4:junit4]   2> 19849 T1859 C140 P45397 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 19850 T1859 C140 P45397 oass.SolrIndexSearcher.<init> Opening Searcher@5d48fcb main
[junit4:junit4]   2> 19850 T1858 oasc.SolrCore.registerSearcher [unloadcollection3] Registered new searcher Searcher@5d48fcb main{StandardDirectoryReader(segments_4:3:nrt _0(5.0):C3)}
[junit4:junit4]   2> 19851 T1859 C140 P45397 oasc.RecoveryStrategy.replay No replay needed. core=unloadcollection3
[junit4:junit4]   2> 19851 T1859 C140 P45397 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=unloadcollection3
[junit4:junit4]   2> 19851 T1859 C140 P45397 oasc.ZkController.publish publishing core=unloadcollection3 state=active
[junit4:junit4]   2> 19851 T1859 C140 P45397 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 19852 T1859 C140 P45397 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=unloadcollection3
[junit4:junit4]   2> 19884 T1789 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19885 T1789 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"unloadcollection3",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:45397_x_oin%2Fu_unloadcollection3",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "collection":"unloadcollection",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:45397_x_oin%2Fu",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:45397/x_oin/u"}
[junit4:junit4]   2> 19900 T1820 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 19900 T1852 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 19900 T1834 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 19900 T1788 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 19900 T1806 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 19900 T1848 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 19900 T1793 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20804 T1766 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20805 T1766 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: unloadcollection
[junit4:junit4]   2> 20805 T1766 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2>  C140_STATE=coll:unloadcollection core:unloadcollection3 props:{core=unloadcollection3, state=active, collection=unloadcollection, shard=shard1, node_name=127.0.0.1:45397_x_oin%2Fu, base_url=http://127.0.0.1:45397/x_oin/u}
[junit4:junit4]   2> 20819 T1828 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[20 (1429970231283941376)]} 0 2
[junit4:junit4]   2> 20819 T1815 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[20 (1429970231283941376)]} 0 1
[junit4:junit4]   2> 20820 T1799 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[20 (1429970231283941376)]} 0 6
[junit4:junit4]   2> 20820 T1827 C140 P45397 /update {wt=javabin&version=2} {add=[20]} 0 8
[junit4:junit4]   2> 20828 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[21 (1429970231293378560)]} 0 1
[junit4:junit4]   2> 20829 T1830 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[21 (1429970231293378560)]} 0 2
[junit4:junit4]   2> 20829 T1802 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[21 (1429970231293378560)]} 0 5
[junit4:junit4]   2> 20830 T1829 C140 P45397 /update {wt=javabin&version=2} {add=[21]} 0 7
[junit4:junit4]   2> 20837 T1827 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[22 (1429970231303864320)]} 0 0
[junit4:junit4]   2> 20837 T1813 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[22 (1429970231303864320)]} 0 0
[junit4:junit4]   2> 20838 T1801 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[22 (1429970231303864320)]} 0 4
[junit4:junit4]   2> 20839 T1828 C140 P45397 /update {wt=javabin&version=2} {add=[22]} 0 7
[junit4:junit4]   2> 20846 T1814 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[23 (1429970231313301504)]} 0 1
[junit4:junit4]   2> 20846 T1829 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[23 (1429970231313301504)]} 0 1
[junit4:junit4]   2> 20846 T1800 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[23 (1429970231313301504)]} 0 3
[junit4:junit4]   2> 20847 T1830 C140 P45397 /update {wt=javabin&version=2} {add=[23]} 0 6
[junit4:junit4]   2> 20853 T1815 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[24 (1429970231320641536)]} 0 1
[junit4:junit4]   2> 20853 T1828 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[24 (1429970231320641536)]} 0 1
[junit4:junit4]   2> 20854 T1799 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[24 (1429970231320641536)]} 0 4
[junit4:junit4]   2> 20854 T1827 C140 P45397 /update {wt=javabin&version=2} {add=[24]} 0 5
[junit4:junit4]   2> 20860 T1830 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[25 (1429970231329030144)]} 0 0
[junit4:junit4]   2> 20860 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[25 (1429970231329030144)]} 0 0
[junit4:junit4]   2> 20861 T1802 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[25 (1429970231329030144)]} 0 3
[junit4:junit4]   2> 20861 T1829 C140 P45397 /update {wt=javabin&version=2} {add=[25]} 0 5
[junit4:junit4]   2> 20868 T1827 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[26 (1429970231336370176)]} 0 1
[junit4:junit4]   2> 20868 T1813 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[26 (1429970231336370176)]} 0 1
[junit4:junit4]   2> 20869 T1801 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[26 (1429970231336370176)]} 0 4
[junit4:junit4]   2> 20869 T1828 C140 P45397 /update {wt=javabin&version=2} {add=[26]} 0 6
[junit4:junit4]   2> 20875 T1814 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[27 (1429970231344758784)]} 0 0
[junit4:junit4]   2> 20876 T1829 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[27 (1429970231344758784)]} 0 1
[junit4:junit4]   2> 20876 T1800 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[27 (1429970231344758784)]} 0 3
[junit4:junit4]   2> 20876 T1830 C140 P45397 /update {wt=javabin&version=2} {add=[27]} 0 5
[junit4:junit4]   2> 20883 T1815 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[28 (1429970231352098816)]} 0 1
[junit4:junit4]   2> 20883 T1828 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[28 (1429970231352098816)]} 0 1
[junit4:junit4]   2> 20884 T1799 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[28 (1429970231352098816)]} 0 4
[junit4:junit4]   2> 20884 T1827 C140 P45397 /update {wt=javabin&version=2} {add=[28]} 0 6
[junit4:junit4]   2> 20891 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[29 (1429970231360487424)]} 0 1
[junit4:junit4]   2> 20891 T1830 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[29 (1429970231360487424)]} 0 1
[junit4:junit4]   2> 20891 T1802 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[29 (1429970231360487424)]} 0 3
[junit4:junit4]   2> 20892 T1829 C140 P45397 /update {wt=javabin&version=2} {add=[29]} 0 6
[junit4:junit4]   2> 20898 T1827 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[30 (1429970231368876032)]} 0 0
[junit4:junit4]   2> 20898 T1813 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[30 (1429970231368876032)]} 0 0
[junit4:junit4]   2> 20899 T1801 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[30 (1429970231368876032)]} 0 4
[junit4:junit4]   2> 20899 T1828 C140 P45397 /update {wt=javabin&version=2} {add=[30]} 0 5
[junit4:junit4]   2> 20906 T1829 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[31 (1429970231376216064)]} 0 1
[junit4:junit4]   2> 20906 T1814 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[31 (1429970231376216064)]} 0 1
[junit4:junit4]   2> 20906 T1800 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[31 (1429970231376216064)]} 0 3
[junit4:junit4]   2> 20907 T1830 C140 P45397 /update {wt=javabin&version=2} {add=[31]} 0 6
[junit4:junit4]   2> 20913 T1815 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[32 (1429970231383556096)]} 0 1
[junit4:junit4]   2> 20913 T1828 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[32 (1429970231383556096)]} 0 1
[junit4:junit4]   2> 20914 T1799 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[32 (1429970231383556096)]} 0 4
[junit4:junit4]   2> 20914 T1827 C140 P45397 /update {wt=javabin&version=2} {add=[32]} 0 5
[junit4:junit4]   2> 20920 T1830 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[33 (1429970231391944704)]} 0 0
[junit4:junit4]   2> 20920 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[33 (1429970231391944704)]} 0 0
[junit4:junit4]   2> 20921 T1802 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[33 (1429970231391944704)]} 0 3
[junit4:junit4]   2> 20921 T1829 C140 P45397 /update {wt=javabin&version=2} {add=[33]} 0 5
[junit4:junit4]   2> 20928 T1827 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[34 (1429970231399284736)]} 0 1
[junit4:junit4]   2> 20928 T1813 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[34 (1429970231399284736)]} 0 1
[junit4:junit4]   2> 20928 T1801 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[34 (1429970231399284736)]} 0 3
[junit4:junit4]   2> 20929 T1828 C140 P45397 /update {wt=javabin&version=2} {add=[34]} 0 6
[junit4:junit4]   2> 20935 T1814 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[35 (1429970231407673344)]} 0 0
[junit4:junit4]   2> 20935 T1829 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[35 (1429970231407673344)]} 0 0
[junit4:junit4]   2> 20936 T1800 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[35 (1429970231407673344)]} 0 3
[junit4:junit4]   2> 20936 T1830 C140 P45397 /update {wt=javabin&version=2} {add=[35]} 0 5
[junit4:junit4]   2> 20943 T1815 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[36 (1429970231415013376)]} 0 0
[junit4:junit4]   2> 20943 T1828 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[36 (1429970231415013376)]} 0 0
[junit4:junit4]   2> 20944 T1799 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[36 (1429970231415013376)]} 0 4
[junit4:junit4]   2> 20945 T1827 C140 P45397 /update {wt=javabin&version=2} {add=[36]} 0 7
[junit4:junit4]   2> 20952 T1830 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[37 (1429970231424450560)]} 0 1
[junit4:junit4]   2> 20952 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[37 (1429970231424450560)]} 0 1
[junit4:junit4]   2> 20953 T1802 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[37 (1429970231424450560)]} 0 4
[junit4:junit4]   2> 20953 T1829 C140 P45397 /update {wt=javabin&version=2} {add=[37]} 0 6
[junit4:junit4]   2> 20961 T1827 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[38 (1429970231433887744)]} 0 1
[junit4:junit4]   2> 20961 T1813 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[38 (1429970231433887744)]} 0 1
[junit4:junit4]   2> 20961 T1801 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[38 (1429970231433887744)]} 0 3
[junit4:junit4]   2> 20962 T1828 C140 P45397 /update {wt=javabin&version=2} {add=[38]} 0 6
[junit4:junit4]   2> 20969 T1829 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[39 (1429970231442276352)]} 0 1
[junit4:junit4]   2> 20969 T1814 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[39 (1429970231442276352)]} 0 1
[junit4:junit4]   2> 20970 T1800 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[39 (1429970231442276352)]} 0 4
[junit4:junit4]   2> 20970 T1830 C140 P45397 /update {wt=javabin&version=2} {add=[39]} 0 6
[junit4:junit4]   2> 20976 T1815 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[40 (1429970231450664960)]} 0 0
[junit4:junit4]   2> 20977 T1828 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[40 (1429970231450664960)]} 0 1
[junit4:junit4]   2> 20977 T1799 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[40 (1429970231450664960)]} 0 3
[junit4:junit4]   2> 20978 T1827 C140 P45397 /update {wt=javabin&version=2} {add=[40]} 0 6
[junit4:junit4]   2> 20984 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[41 (1429970231459053568)]} 0 0
[junit4:junit4]   2> 20984 T1830 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[41 (1429970231459053568)]} 0 0
[junit4:junit4]   2> 20985 T1802 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[41 (1429970231459053568)]} 0 3
[junit4:junit4]   2> 20985 T1829 C140 P45397 /update {wt=javabin&version=2} {add=[41]} 0 5
[junit4:junit4]   2> 20991 T1827 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[42 (1429970231466393600)]} 0 0
[junit4:junit4]   2> 20992 T1813 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[42 (1429970231466393600)]} 0 1
[junit4:junit4]   2> 20992 T1801 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[42 (1429970231466393600)]} 0 3
[junit4:junit4]   2> 20992 T1828 C140 P45397 /update {wt=javabin&version=2} {add=[42]} 0 5
[junit4:junit4]   2> 20999 T1814 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[43 (1429970231474782208)]} 0 0
[junit4:junit4]   2> 20999 T1829 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[43 (1429970231474782208)]} 0 0
[junit4:junit4]   2> 21000 T1800 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[43 (1429970231474782208)]} 0 4
[junit4:junit4]   2> 21000 T1830 C140 P45397 /update {wt=javabin&version=2} {add=[43]} 0 5
[junit4:junit4]   2> 21007 T1815 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[44 (1429970231482122240)]} 0 1
[junit4:junit4]   2> 21007 T1829 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[44 (1429970231482122240)]} 0 1
[junit4:junit4]   2> 21008 T1799 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[44 (1429970231482122240)]} 0 4
[junit4:junit4]   2> 21008 T1828 C140 P45397 /update {wt=javabin&version=2} {add=[44]} 0 6
[junit4:junit4]   2> 21015 T1830 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[45 (1429970231490510848)]} 0 1
[junit4:junit4]   2> 21015 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[45 (1429970231490510848)]} 0 1
[junit4:junit4]   2> 21015 T1801 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[45 (1429970231490510848)]} 0 3
[junit4:junit4]   2> 21016 T1827 C140 P45397 /update {wt=javabin&version=2} {add=[45]} 0 6
[junit4:junit4]   2> 21022 T1830 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[46 (1429970231498899456)]} 0 0
[junit4:junit4]   2> 21022 T1813 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[46 (1429970231498899456)]} 0 0
[junit4:junit4]   2> 21023 T1800 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[46 (1429970231498899456)]} 0 4
[junit4:junit4]   2> 21023 T1828 C140 P45397 /update {wt=javabin&version=2} {add=[46]} 0 5
[junit4:junit4]   2> 21030 T1814 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[47 (1429970231506239488)]} 0 1
[junit4:junit4]   2> 21030 T1829 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[47 (1429970231506239488)]} 0 1
[junit4:junit4]   2> 21030 T1802 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[47 (1429970231506239488)]} 0 3
[junit4:junit4]   2> 21031 T1827 C140 P45397 /update {wt=javabin&version=2} {add=[47]} 0 6
[junit4:junit4]   2> 21037 T1815 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[48 (1429970231513579520)]} 0 0
[junit4:junit4]   2> 21037 T1828 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[48 (1429970231513579520)]} 0 1
[junit4:junit4]   2> 21038 T1799 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[48 (1429970231513579520)]} 0 4
[junit4:junit4]   2> 21038 T1830 C140 P45397 /update {wt=javabin&version=2} {add=[48]} 0 5
[junit4:junit4]   2> 21045 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[49 (1429970231521968128)]} 0 1
[junit4:junit4]   2> 21045 T1827 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[49 (1429970231521968128)]} 0 1
[junit4:junit4]   2> 21045 T1801 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[49 (1429970231521968128)]} 0 3
[junit4:junit4]   2> 21046 T1829 C140 P45397 /update {wt=javabin&version=2} {add=[49]} 0 6
[junit4:junit4]   2> 21052 T1830 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[50 (1429970231530356736)]} 0 0
[junit4:junit4]   2> 21052 T1813 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[50 (1429970231530356736)]} 0 0
[junit4:junit4]   2> 21053 T1800 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[50 (1429970231530356736)]} 0 3
[junit4:junit4]   2> 21053 T1828 C140 P45397 /update {wt=javabin&version=2} {add=[50]} 0 5
[junit4:junit4]   2> 21060 T1829 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[51 (1429970231538745344)]} 0 0
[junit4:junit4]   2> 21060 T1814 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[51 (1429970231538745344)]} 0 0
[junit4:junit4]   2> 21061 T1802 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[51 (1429970231538745344)]} 0 4
[junit4:junit4]   2> 21061 T1827 C140 P45397 /update {wt=javabin&version=2} {add=[51]} 0 5
[junit4:junit4]   2> 21068 T1815 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[52 (1429970231546085376)]} 0 1
[junit4:junit4]   2> 21068 T1828 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[52 (1429970231546085376)]} 0 1
[junit4:junit4]   2> 21068 T1799 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[52 (1429970231546085376)]} 0 3
[junit4:junit4]   2> 21069 T1830 C140 P45397 /update {wt=javabin&version=2} {add=[52]} 0 6
[junit4:junit4]   2> 21075 T1827 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[53 (1429970231554473984)]} 0 0
[junit4:junit4]   2> 21075 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[53 (1429970231554473984)]} 0 0
[junit4:junit4]   2> 21076 T1801 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[53 (1429970231554473984)]} 0 3
[junit4:junit4]   2> 21076 T1829 C140 P45397 /update {wt=javabin&version=2} {add=[53]} 0 5
[junit4:junit4]   2> 21083 T1830 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[54 (1429970231562862592)]} 0 0
[junit4:junit4]   2> 21083 T1813 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[54 (1429970231562862592)]} 0 0
[junit4:junit4]   2> 21084 T1800 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[54 (1429970231562862592)]} 0 4
[junit4:junit4]   2> 21084 T1828 C140 P45397 /update {wt=javabin&version=2} {add=[54]} 0 6
[junit4:junit4]   2> 21091 T1829 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[55 (1429970231570202624)]} 0 1
[junit4:junit4]   2> 21091 T1814 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[55 (1429970231570202624)]} 0 1
[junit4:junit4]   2> 21091 T1802 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[55 (1429970231570202624)]} 0 3
[junit4:junit4]   2> 21092 T1827 C140 P45397 /update {wt=javabin&version=2} {add=[55]} 0 5
[junit4:junit4]   2> 21098 T1815 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[56 (1429970231578591232)]} 0 0
[junit4:junit4]   2> 21099 T1828 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[56 (1429970231578591232)]} 0 1
[junit4:junit4]   2> 21099 T1799 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[56 (1429970231578591232)]} 0 3
[junit4:junit4]   2> 21100 T1830 C140 P45397 /update {wt=javabin&version=2} {add=[56]} 0 6
[junit4:junit4]   2> 21106 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[57 (1429970231586979840)]} 0 0
[junit4:junit4]   2> 21106 T1827 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[57 (1429970231586979840)]} 0 0
[junit4:junit4]   2> 21107 T1801 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[57 (1429970231586979840)]} 0 4
[junit4:junit4]   2> 21107 T1829 C140 P45397 /update {wt=javabin&version=2} {add=[57]} 0 5
[junit4:junit4]   2> 21114 T1830 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[58 (1429970231594319872)]} 0 1
[junit4:junit4]   2> 21114 T1813 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[58 (1429970231594319872)]} 0 1
[junit4:junit4]   2> 21115 T1800 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[58 (1429970231594319872)]} 0 4
[junit4:junit4]   2> 21115 T1828 C140 P45397 /update {wt=javabin&version=2} {add=[58]} 0 6
[junit4:junit4]   2> 21122 T1814 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[59 (1429970231602708480)]} 0 1
[junit4:junit4]   2> 21122 T1829 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[59 (1429970231602708480)]} 0 1
[junit4:junit4]   2> 21122 T1802 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[59 (1429970231602708480)]} 0 3
[junit4:junit4]   2> 21123 T1827 C140 P45397 /update {wt=javabin&version=2} {add=[59]} 0 6
[junit4:junit4]   2> 21129 T1815 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[60 (1429970231610048512)]} 0 0
[junit4:junit4]   2> 21130 T1828 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[60 (1429970231610048512)]} 0 1
[junit4:junit4]   2> 21130 T1799 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[60 (1429970231610048512)]} 0 4
[junit4:junit4]   2> 21131 T1830 C140 P45397 /update {wt=javabin&version=2} {add=[60]} 0 6
[junit4:junit4]   2> 21137 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[61 (1429970231619485696)]} 0 0
[junit4:junit4]   2> 21137 T1827 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[61 (1429970231619485696)]} 0 0
[junit4:junit4]   2> 21138 T1801 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[61 (1429970231619485696)]} 0 3
[junit4:junit4]   2> 21138 T1829 C140 P45397 /update {wt=javabin&version=2} {add=[61]} 0 5
[junit4:junit4]   2> 21145 T1830 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[62 (1429970231626825728)]} 0 1
[junit4:junit4]   2> 21145 T1813 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[62 (1429970231626825728)]} 0 1
[junit4:junit4]   2> 21146 T1800 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[62 (1429970231626825728)]} 0 4
[junit4:junit4]   2> 21146 T1828 C140 P45397 /update {wt=javabin&version=2} {add=[62]} 0 6
[junit4:junit4]   2> 21153 T1829 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[63 (1429970231635214336)]} 0 1
[junit4:junit4]   2> 21153 T1814 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[63 (1429970231635214336)]} 0 1
[junit4:junit4]   2> 21153 T1802 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[63 (1429970231635214336)]} 0 3
[junit4:junit4]   2> 21154 T1827 C140 P45397 /update {wt=javabin&version=2} {add=[63]} 0 6
[junit4:junit4]   2> 21160 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[64 (1429970231643602944)]} 0 0
[junit4:junit4]   2> 21160 T1828 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[64 (1429970231643602944)]} 0 0
[junit4:junit4]   2> 21161 T1799 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[64 (1429970231643602944)]} 0 4
[junit4:junit4]   2> 21161 T1830 C140 P45397 /update {wt=javabin&version=2} {add=[64]} 0 5
[junit4:junit4]   2> 21168 T1827 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[65 (1429970231650942976)]} 0 1
[junit4:junit4]   2> 21168 T1813 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[65 (1429970231650942976)]} 0 1
[junit4:junit4]   2> 21168 T1801 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[65 (1429970231650942976)]} 0 3
[junit4:junit4]   2> 21169 T1829 C140 P45397 /update {wt=javabin&version=2} {add=[65]} 0 6
[junit4:junit4]   2> 21175 T1830 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[66 (1429970231659331584)]} 0 0
[junit4:junit4]   2> 21175 T1815 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[66 (1429970231659331584)]} 0 0
[junit4:junit4]   2> 21176 T1800 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[66 (1429970231659331584)]} 0 3
[junit4:junit4]   2> 21176 T1828 C140 P45397 /update {wt=javabin&version=2} {add=[66]} 0 5
[junit4:junit4]   2> 21183 T1814 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[67 (1429970231666671616)]} 0 1
[junit4:junit4]   2> 21183 T1829 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[67 (1429970231666671616)]} 0 1
[junit4:junit4]   2> 21183 T1802 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[67 (1429970231666671616)]} 0 3
[junit4:junit4]   2> 21184 T1827 C140 P45397 /update {wt=javabin&version=2} {add=[67]} 0 6
[junit4:junit4]   2> 21190 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[68 (1429970231675060224)]} 0 0
[junit4:junit4]   2> 21190 T1828 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[68 (1429970231675060224)]} 0 0
[junit4:junit4]   2> 21191 T1799 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[68 (1429970231675060224)]} 0 3
[junit4:junit4]   2> 21191 T1830 C140 P45397 /update {wt=javabin&version=2} {add=[68]} 0 5
[junit4:junit4]   2> 21198 T1827 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[69 (1429970231682400256)]} 0 0
[junit4:junit4]   2> 21198 T1813 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[69 (1429970231682400256)]} 0 0
[junit4:junit4]   2> 21199 T1801 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[69 (1429970231682400256)]} 0 4
[junit4:junit4]   2> 21199 T1829 C140 P45397 /update {wt=javabin&version=2} {add=[69]} 0 6
[junit4:junit4]   2> 21206 T1830 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[70 (1429970231690788864)]} 0 1
[junit4:junit4]   2> 21206 T1815 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[70 (1429970231690788864)]} 0 1
[junit4:junit4]   2> 21206 T1800 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[70 (1429970231690788864)]} 0 3
[junit4:junit4]   2> 21207 T1828 C140 P45397 /update {wt=javabin&version=2} {add=[70]} 0 6
[junit4:junit4]   2> 21214 T1814 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[71 (1429970231699177472)]} 0 1
[junit4:junit4]   2> 21214 T1829 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[71 (1429970231699177472)]} 0 1
[junit4:junit4]   2> 21214 T1802 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[71 (1429970231699177472)]} 0 3
[junit4:junit4]   2> 21215 T1827 C140 P45397 /update {wt=javabin&version=2} {add=[71]} 0 6
[junit4:junit4]   2> 21221 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[72 (1429970231707566080)]} 0 0
[junit4:junit4]   2> 21221 T1828 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[72 (1429970231707566080)]} 0 0
[junit4:junit4]   2> 21222 T1801 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[72 (1429970231707566080)]} 0 3
[junit4:junit4]   2> 21222 T1830 C140 P45397 /update {wt=javabin&version=2} {add=[72]} 0 5
[junit4:junit4]   2> 21229 T1827 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[73 (1429970231714906112)]} 0 1
[junit4:junit4]   2> 21229 T1813 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[73 (1429970231714906112)]} 0 1
[junit4:junit4]   2> 21230 T1800 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[73 (1429970231714906112)]} 0 4
[junit4:junit4]   2> 21230 T1829 C140 P45397 /update {wt=javabin&version=2} {add=[73]} 0 6
[junit4:junit4]   2> 21237 T1830 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[74 (1429970231723294720)]} 0 1
[junit4:junit4]   2> 21237 T1815 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[74 (1429970231723294720)]} 0 1
[junit4:junit4]   2> 21237 T1802 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[74 (1429970231723294720)]} 0 3
[junit4:junit4]   2> 21238 T1828 C140 P45397 /update {wt=javabin&version=2} {add=[74]} 0 6
[junit4:junit4]   2> 21244 T1829 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[75 (1429970231731683328)]} 0 0
[junit4:junit4]   2> 21244 T1814 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[75 (1429970231731683328)]} 0 0
[junit4:junit4]   2> 21245 T1799 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[75 (1429970231731683328)]} 0 3
[junit4:junit4]   2> 21245 T1827 C140 P45397 /update {wt=javabin&version=2} {add=[75]} 0 5
[junit4:junit4]   2> 21252 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[76 (1429970231739023360)]} 0 1
[junit4:junit4]   2> 21252 T1828 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[76 (1429970231739023360)]} 0 1
[junit4:junit4]   2> 21253 T1801 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[76 (1429970231739023360)]} 0 4
[junit4:junit4]   2> 21253 T1830 C140 P45397 /update {wt=javabin&version=2} {add=[76]} 0 6
[junit4:junit4]   2> 21260 T1827 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[77 (1429970231747411968)]} 0 1
[junit4:junit4]   2> 21260 T1813 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[77 (1429970231747411968)]} 0 1
[junit4:junit4]   2> 21260 T1800 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[77 (1429970231747411968)]} 0 3
[junit4:junit4]   2> 21261 T1829 C140 P45397 /update {wt=javabin&version=2} {add=[77]} 0 6
[junit4:junit4]   2> 21267 T1815 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[78 (1429970231755800576)]} 0 0
[junit4:junit4]   2> 21267 T1830 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[78 (1429970231755800576)]} 0 0
[junit4:junit4]   2> 21268 T1802 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[78 (1429970231755800576)]} 0 4
[junit4:junit4]   2> 21268 T1828 C140 P45397 /update {wt=javabin&version=2} {add=[78]} 0 5
[junit4:junit4]   2> 21275 T1814 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[79 (1429970231763140608)]} 0 1
[junit4:junit4]   2> 21275 T1829 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[79 (1429970231763140608)]} 0 1
[junit4:junit4]   2> 21283 T1799 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[79 (1429970231763140608)]} 0 11
[junit4:junit4]   2> 21284 T1827 C140 P45397 /update {wt=javabin&version=2} {add=[79]} 0 14
[junit4:junit4]   2> 21291 T1828 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[80 (1429970231779917824)]} 0 1
[junit4:junit4]   2> 21291 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[80 (1429970231779917824)]} 0 1
[junit4:junit4]   2> 21291 T1801 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[80 (1429970231779917824)]} 0 3
[junit4:junit4]   2> 21292 T1830 C140 P45397 /update {wt=javabin&version=2} {add=[80]} 0 6
[junit4:junit4]   2> 21298 T1827 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[81 (1429970231788306432)]} 0 0
[junit4:junit4]   2> 21299 T1813 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[81 (1429970231788306432)]} 0 1
[junit4:junit4]   2> 21299 T1800 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[81 (1429970231788306432)]} 0 3
[junit4:junit4]   2> 21300 T1829 C140 P45397 /update {wt=javabin&version=2} {add=[81]} 0 6
[junit4:junit4]   2> 21306 T1815 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[82 (1429970231796695040)]} 0 0
[junit4:junit4]   2> 21306 T1830 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[82 (1429970231796695040)]} 0 0
[junit4:junit4]   2> 21307 T1802 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[82 (1429970231796695040)]} 0 3
[junit4:junit4]   2> 21307 T1828 C140 P45397 /update {wt=javabin&version=2} {add=[82]} 0 5
[junit4:junit4]   2> 21314 T1814 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[83 (1429970231804035072)]} 0 1
[junit4:junit4]   2> 21314 T1829 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[83 (1429970231804035072)]} 0 1
[junit4:junit4]   2> 21315 T1799 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[83 (1429970231804035072)]} 0 4
[junit4:junit4]   2> 21315 T1827 C140 P45397 /update {wt=javabin&version=2} {add=[83]} 0 6
[junit4:junit4]   2> 21322 T1828 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[84 (1429970231812423680)]} 0 1
[junit4:junit4]   2> 21322 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[84 (1429970231812423680)]} 0 1
[junit4:junit4]   2> 21323 T1801 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[84 (1429970231812423680)]} 0 4
[junit4:junit4]   2> 21323 T1830 C140 P45397 /update {wt=javabin&version=2} {add=[84]} 0 6
[junit4:junit4]   2> 21330 T1813 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[85 (1429970231820812288)]} 0 1
[junit4:junit4]   2> 21330 T1827 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[85 (1429970231820812288)]} 0 0
[junit4:junit4]   2> 21330 T1800 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[85 (1429970231820812288)]} 0 3
[junit4:junit4]   2> 21330 T1829 C140 P45397 /update {wt=javabin&version=2} {add=[85]} 0 5
[junit4:junit4]   2> 21337 T1815 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[86 (1429970231828152320)]} 0 1
[junit4:junit4]   2> 21337 T1830 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[86 (1429970231828152320)]} 0 1
[junit4:junit4]   2> 21337 T1802 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[86 (1429970231828152320)]} 0 3
[junit4:junit4]   2> 21338 T1828 C140 P45397 /update {wt=javabin&version=2} {add=[86]} 0 6
[junit4:junit4]   2> 21344 T1814 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[87 (1429970231835492352)]} 0 1
[junit4:junit4]   2> 21344 T1829 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[87 (1429970231835492352)]} 0 1
[junit4:junit4]   2> 21344 T1799 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_oin/u/unloadcollection3/&version=2&update.distrib=TOLEADER} {add=[87 (1429970231835492352)]} 0 3
[junit4:junit4]   2> 21345 T1827 C140 P45397 /update {wt=javabin&version=2} {add=[87]} 0 5
[junit4:junit4]   2> 21351 T1828 C140 P45397 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[88 (1429970231843880960)]} 0 0
[junit4:junit4]   2> 21351 T1816 C138 P42905 /update {wt=javabin&distrib.from=http://127.0.0.1:53441/x_oin/u/unloadcollection1/&version=2&update.distrib=FROMLEADER} {add=[88 (1429970231843880960)]} 0 0
[junit4:junit4]   2> 21352 T1801 C139 P53441 /update {wt=javabin&distrib.from=http://127.0.0.1:45397/x_

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

e":"recovery_failed",
[junit4:junit4]   1>                   "collection":"multiunload",
[junit4:junit4]   1>                   "shard":"shard1",
[junit4:junit4]   1>                   "node_name":"127.0.0.1:45397_x_oin%2Fu",
[junit4:junit4]   1>                   "base_url":"http://127.0.0.1:45397/x_oin/u"}}}}}}
[junit4:junit4]   1> 
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=UnloadDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=E9E1A105D350FB69 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_CO -Dtests.timezone=Asia/Kamchatka -Dtests.file.encoding=UTF-8
[junit4:junit4] FAILURE  139s J1 | UnloadDistributedZkTest.testDistribSearch <<<
[junit4:junit4]    > Throwable #1: java.lang.AssertionError: Still found shard2 in collection test_unload_shard_and_collection
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([E9E1A105D350FB69:68072F1DA40F9B55]:0)
[junit4:junit4]    > 	at org.junit.Assert.fail(Assert.java:93)
[junit4:junit4]    > 	at org.apache.solr.cloud.UnloadDistributedZkTest.testUnloadShardAndCollection(UnloadDistributedZkTest.java:124)
[junit4:junit4]    > 	at org.apache.solr.cloud.UnloadDistributedZkTest.doTest(UnloadDistributedZkTest.java:77)
[junit4:junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4:junit4]    > 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4:junit4]    > 	at java.lang.reflect.Method.invoke(Method.java:487)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 139121 T1766 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> 139129 T1765 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4]   2> 140214 T1848 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 140214 T1848 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> 140215 T1848 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 140215 T1848 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> NOTE: test params are: codec=CheapBastard, sim=DefaultSimilarity, locale=es_CO, timezone=Asia/Kamchatka
[junit4:junit4]   2> NOTE: Linux 3.2.0-39-generic amd64/Oracle Corporation 1.8.0-ea (64-bit)/cpus=8,threads=1,free=31859800,total=357171200
[junit4:junit4]   2> NOTE: All tests run in this JVM: [CopyFieldTest, SpellPossibilityIteratorTest, BadIndexSchemaTest, StatsComponentTest, TestDistributedGrouping, SolrCmdDistributorTest, TestSolr4Spatial, HighlighterTest, TestQueryTypes, SpellCheckComponentTest, DirectSolrSpellCheckerTest, JSONWriterTest, TestRecovery, DocumentAnalysisRequestHandlerTest, TestRangeQuery, EchoParamsTest, TestRTGBase, DistanceFunctionTest, SpellCheckCollatorTest, UpdateParamsTest, XsltUpdateRequestHandlerTest, TestDefaultSimilarityFactory, TestJmxIntegration, DocValuesMultiTest, TestBM25SimilarityFactory, ZkSolrClientTest, TestFiltering, TestJmxMonitoredMap, LeaderElectionIntegrationTest, NoCacheHeaderTest, TestLazyCores, TestQuerySenderNoQuery, TestElisionMultitermQuery, PathHierarchyTokenizerFactoryTest, DefaultValueUpdateProcessorTest, TestFieldTypeResource, PingRequestHandlerTest, FieldAnalysisRequestHandlerTest, TestReload, TestCSVResponseWriter, TestBinaryResponseWriter, HardAutoCommitTest, TestMergePolicyConfig, UniqFieldsUpdateProcessorFactoryTest, FullSolrCloudDistribCmdsTest, TestUtils, TestFastOutputStream, NumericFieldsTest, ConvertedLegacyTest, SuggesterWFSTTest, TestBinaryField, TestRandomFaceting, StandardRequestHandlerTest, TestSuggestSpellingConverter, TestFoldingMultitermQuery, SolrCoreCheckLockOnStartupTest, SolrPluginUtilsTest, CurrencyFieldOpenExchangeTest, ClusterStateTest, ShardRoutingCustomTest, ZkNodePropsTest, DisMaxRequestHandlerTest, TermVectorComponentDistributedTest, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest]
[junit4:junit4] Completed on J1 in 140.41s, 1 test, 1 failure <<< FAILURES!

[...truncated 414 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:375: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:355: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:183: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:449: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1210: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:874: There were test failures: 272 suites, 1144 tests, 1 failure, 13 ignored (7 assumptions)

Total time: 38 minutes 46 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 64bit/jdk1.8.0-ea-b79 -XX:+UseParallelGC
Email was triggered for: Failure
Sending email for trigger: Failure