lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.8.0-ea-b65) - Build # 4442 - Failure!
Date Sat, 23 Feb 2013 12:48:30 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/4442/
Java: 32bit/jdk1.8.0-ea-b65 -server -XX:+UseParallelGC

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

Error Message:
Still found shard

Stack Trace:
java.lang.AssertionError: Still found shard
	at __randomizedtesting.SeedInfo.seed([DEEFF79ABA7FFC5B:5F097982CD209C67]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.UnloadDistributedZkTest.testUnloadShardAndCollection(UnloadDistributedZkTest.java:120)
	at org.apache.solr.cloud.UnloadDistributedZkTest.doTest(UnloadDistributedZkTest.java:73)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:794)
	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:474)
	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 9585 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.UnloadDistributedZkTest
[junit4:junit4]   2> 0 T3679 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /kbo/zj
[junit4:junit4]   2> 3 T3679 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-1361623555471
[junit4:junit4]   2> 3 T3679 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 4 T3680 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 4 T3680 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 4 T3680 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4]   2> 5 T3680 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4]   2> 5 T3680 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 5 T3680 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-1361623555471/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4]   2> 104 T3679 oasc.ZkTestServer.run start zk server on port:42099
[junit4:junit4]   2> 104 T3679 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42099 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@85f491
[junit4:junit4]   2> 105 T3679 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 105 T3685 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42099. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 106 T3685 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42099, initiating session
[junit4:junit4]   2> 106 T3681 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:43704
[junit4:junit4]   2> 106 T3681 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:43704
[junit4:junit4]   2> 106 T3683 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 431 T3683 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d07169d920000 with negotiated timeout 10000 for client /127.0.0.1:43704
[junit4:junit4]   2> 431 T3685 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42099, sessionid = 0x13d07169d920000, negotiated timeout = 10000
[junit4:junit4]   2> 431 T3686 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@85f491 name:ZooKeeperConnection Watcher:127.0.0.1:42099 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 431 T3679 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 432 T3679 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 434 T3684 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d07169d920000
[junit4:junit4]   2> 435 T3686 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 435 T3681 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:43704 which had sessionid 0x13d07169d920000
[junit4:junit4]   2> 434 T3679 oaz.ZooKeeper.close Session: 0x13d07169d920000 closed
[junit4:junit4]   2> 435 T3679 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42099/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@bfd9fc
[junit4:junit4]   2> 436 T3687 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42099. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 436 T3679 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 436 T3687 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42099, initiating session
[junit4:junit4]   2> 436 T3681 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:43705
[junit4:junit4]   2> 437 T3681 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:43705
[junit4:junit4]   2> 437 T3683 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d07169d920001 with negotiated timeout 10000 for client /127.0.0.1:43705
[junit4:junit4]   2> 437 T3687 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42099, sessionid = 0x13d07169d920001, negotiated timeout = 10000
[junit4:junit4]   2> 437 T3688 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bfd9fc name:ZooKeeperConnection Watcher:127.0.0.1:42099/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 438 T3679 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 438 T3679 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 440 T3679 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 442 T3679 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 443 T3679 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 445 T3679 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> 446 T3679 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 448 T3679 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> 449 T3679 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 452 T3679 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> 452 T3679 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 454 T3679 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> 454 T3679 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 456 T3679 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> 457 T3679 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 459 T3679 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> 459 T3679 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 462 T3679 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> 462 T3679 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 464 T3679 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> 465 T3679 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 467 T3679 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> 467 T3679 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 469 T3684 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d07169d920001
[junit4:junit4]   2> 470 T3681 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:43705 which had sessionid 0x13d07169d920001
[junit4:junit4]   2> 470 T3688 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 470 T3679 oaz.ZooKeeper.close Session: 0x13d07169d920001 closed
[junit4:junit4]   2> 535 T3679 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 538 T3679 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47692
[junit4:junit4]   2> 538 T3679 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 539 T3679 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 539 T3679 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-1361623555939
[junit4:junit4]   2> 540 T3679 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361623555939/solr.xml
[junit4:junit4]   2> 540 T3679 oasc.CoreContainer.<init> New CoreContainer 732704
[junit4:junit4]   2> 541 T3679 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-1361623555939/'
[junit4:junit4]   2> 541 T3679 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-1361623555939/'
[junit4:junit4]   2> 558 T3679 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 558 T3679 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 559 T3679 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 559 T3679 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 559 T3679 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 560 T3679 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 560 T3679 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 561 T3679 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 561 T3679 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 561 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 579 T3679 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 588 T3679 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:42099/solr
[junit4:junit4]   2> 589 T3679 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 589 T3679 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42099 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@17221d9
[junit4:junit4]   2> 590 T3698 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42099. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 590 T3679 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 590 T3681 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:43708
[junit4:junit4]   2> 590 T3698 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42099, initiating session
[junit4:junit4]   2> 591 T3681 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:43708
[junit4:junit4]   2> 591 T3683 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d07169d920002 with negotiated timeout 20000 for client /127.0.0.1:43708
[junit4:junit4]   2> 591 T3698 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42099, sessionid = 0x13d07169d920002, negotiated timeout = 20000
[junit4:junit4]   2> 591 T3699 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17221d9 name:ZooKeeperConnection Watcher:127.0.0.1:42099 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 591 T3679 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 592 T3684 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d07169d920002
[junit4:junit4]   2> 593 T3681 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:43708 which had sessionid 0x13d07169d920002
[junit4:junit4]   2> 593 T3679 oaz.ZooKeeper.close Session: 0x13d07169d920002 closed
[junit4:junit4]   2> 593 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 595 T3679 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42099/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@da6c95
[junit4:junit4]   2> 596 T3699 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 596 T3700 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42099. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 596 T3679 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 596 T3700 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42099, initiating session
[junit4:junit4]   2> 596 T3681 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:43709
[junit4:junit4]   2> 596 T3681 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:43709
[junit4:junit4]   2> 598 T3683 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d07169d920003 with negotiated timeout 20000 for client /127.0.0.1:43709
[junit4:junit4]   2> 598 T3700 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42099, sessionid = 0x13d07169d920003, negotiated timeout = 20000
[junit4:junit4]   2> 598 T3701 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@da6c95 name:ZooKeeperConnection Watcher:127.0.0.1:42099/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 598 T3679 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 599 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 600 T3679 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 601 T3679 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47692_kbo%2Fzj
[junit4:junit4]   2> 601 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:47692_kbo%2Fzj Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:47692_kbo%2Fzj
[junit4:junit4]   2> 602 T3679 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47692_kbo%2Fzj
[junit4:junit4]   2> 604 T3679 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 606 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920003 type:delete cxid:0x16 zxid:0x21 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 606 T3679 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 607 T3679 oasc.Overseer.start Overseer (id=89235361331544067-127.0.0.1:47692_kbo%2Fzj-n_0000000000) starting
[junit4:junit4]   2> 608 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 608 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 609 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 609 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 610 T3703 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 610 T3679 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 611 T3679 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 612 T3702 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 615 T3704 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361623555939/collection1
[junit4:junit4]   2> 615 T3704 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 616 T3704 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 616 T3704 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 617 T3704 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-1361623555939/collection1/'
[junit4:junit4]   2> 617 T3704 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361623555939/collection1/lib/README' to classloader
[junit4:junit4]   2> 617 T3704 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361623555939/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 638 T3704 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 667 T3704 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 667 T3704 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 670 T3704 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1018 T3704 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1023 T3704 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1025 T3704 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1032 T3704 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1035 T3704 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1037 T3704 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1037 T3704 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1038 T3704 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361623555939/collection1/, dataDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/control/data/
[junit4:junit4]   2> 1038 T3704 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d0063
[junit4:junit4]   2> 1038 T3704 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 1039 T3704 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/control/data forceNew:false
[junit4:junit4]   2> 1039 T3704 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/control/data
[junit4:junit4]   2> 1039 T3704 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/control/data/index/
[junit4:junit4]   2> 1039 T3704 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1040 T3704 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/control/data/index forceNew:false
[junit4:junit4]   2> 1041 T3704 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@8c5566 lockFactory=org.apache.lucene.store.NativeFSLockFactory@12949db),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1041 T3704 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 1041 T3704 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/control/data/index
[junit4:junit4]   2> 1042 T3704 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1042 T3704 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1042 T3704 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1043 T3704 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1043 T3704 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1043 T3704 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1043 T3704 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1043 T3704 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1044 T3704 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1046 T3704 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1047 T3704 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/control/data
[junit4:junit4]   2> 1048 T3704 oass.SolrIndexSearcher.<init> Opening Searcher@902f26 main
[junit4:junit4]   2> 1048 T3704 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/control/data/tlog
[junit4:junit4]   2> 1048 T3704 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1049 T3704 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1050 T3704 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/control/data
[junit4:junit4]   2> 1051 T3705 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@902f26 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1051 T3704 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 1051 T3704 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1052 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920003 type:create cxid:0x50 zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4]   2> 2116 T3702 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2117 T3702 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:47692/kbo/zj",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:47692_kbo%2Fzj",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "operation":"state"}
[junit4:junit4]   2> 2117 T3702 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 2118 T3702 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 2118 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920003 type:create cxid:0x58 zxid:0x2c txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 2124 T3701 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 3054 T3704 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 3054 T3704 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:47692/kbo/zj collection:control_collection shard:shard1
[junit4:junit4]   2> 3055 T3704 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 3058 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920003 type:delete cxid:0x72 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 3059 T3704 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 3059 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920003 type:create cxid:0x73 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3060 T3704 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 3060 T3704 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 3060 T3704 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:47692/kbo/zj/collection1/
[junit4:junit4]   2> 3060 T3704 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 3061 T3704 oasc.SyncStrategy.syncToMe http://127.0.0.1:47692/kbo/zj/collection1/ has no replicas
[junit4:junit4]   2> 3061 T3704 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:47692/kbo/zj/collection1/
[junit4:junit4]   2> 3061 T3704 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 3063 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920003 type:create cxid:0x7d zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3626 T3702 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3687 T3701 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 3715 T3704 oasc.ZkController.register We are http://127.0.0.1:47692/kbo/zj/collection1/ and leader is http://127.0.0.1:47692/kbo/zj/collection1/
[junit4:junit4]   2> 3716 T3704 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:47692/kbo/zj
[junit4:junit4]   2> 3716 T3704 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 3716 T3704 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 3716 T3704 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 3717 T3704 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3718 T3679 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 3719 T3679 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 3719 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 3723 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 3724 T3679 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42099/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1d49d7a
[junit4:junit4]   2> 3725 T3706 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42099. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 3725 T3679 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3725 T3706 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42099, initiating session
[junit4:junit4]   2> 3725 T3681 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:43711
[junit4:junit4]   2> 3725 T3681 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:43711
[junit4:junit4]   2> 3726 T3683 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d07169d920004 with negotiated timeout 10000 for client /127.0.0.1:43711
[junit4:junit4]   2> 3726 T3706 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42099, sessionid = 0x13d07169d920004, negotiated timeout = 10000
[junit4:junit4]   2> 3726 T3707 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d49d7a name:ZooKeeperConnection Watcher:127.0.0.1:42099/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3726 T3679 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3727 T3679 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3728 T3679 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 3788 T3679 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 3790 T3679 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50766
[junit4:junit4]   2> 3790 T3679 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 3791 T3679 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3791 T3679 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-1361623559197
[junit4:junit4]   2> 3791 T3679 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361623559197/solr.xml
[junit4:junit4]   2> 3792 T3679 oasc.CoreContainer.<init> New CoreContainer 28710457
[junit4:junit4]   2> 3792 T3679 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-1361623559197/'
[junit4:junit4]   2> 3793 T3679 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-1361623559197/'
[junit4:junit4]   2> 3809 T3679 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 3810 T3679 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 3810 T3679 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 3811 T3679 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 3811 T3679 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 3811 T3679 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 3812 T3679 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 3812 T3679 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 3812 T3679 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 3813 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 3818 T3679 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 3827 T3679 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:42099/solr
[junit4:junit4]   2> 3827 T3679 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 3828 T3679 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42099 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1263574
[junit4:junit4]   2> 3828 T3717 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42099. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 3828 T3679 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3829 T3717 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42099, initiating session
[junit4:junit4]   2> 3829 T3681 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:43712
[junit4:junit4]   2> 3829 T3681 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:43712
[junit4:junit4]   2> 3830 T3683 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d07169d920005 with negotiated timeout 20000 for client /127.0.0.1:43712
[junit4:junit4]   2> 3830 T3717 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42099, sessionid = 0x13d07169d920005, negotiated timeout = 20000
[junit4:junit4]   2> 3830 T3718 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1263574 name:ZooKeeperConnection Watcher:127.0.0.1:42099 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3830 T3679 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3831 T3684 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d07169d920005
[junit4:junit4]   2> 3831 T3681 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:43712 which had sessionid 0x13d07169d920005
[junit4:junit4]   2> 3832 T3718 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 3832 T3679 oaz.ZooKeeper.close Session: 0x13d07169d920005 closed
[junit4:junit4]   2> 3832 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 3834 T3679 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42099/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@9c6330
[junit4:junit4]   2> 3835 T3719 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42099. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 3835 T3679 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3835 T3681 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:43713
[junit4:junit4]   2> 3835 T3719 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42099, initiating session
[junit4:junit4]   2> 3836 T3681 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:43713
[junit4:junit4]   2> 3836 T3683 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d07169d920006 with negotiated timeout 20000 for client /127.0.0.1:43713
[junit4:junit4]   2> 3836 T3719 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42099, sessionid = 0x13d07169d920006, negotiated timeout = 20000
[junit4:junit4]   2> 3837 T3720 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9c6330 name:ZooKeeperConnection Watcher:127.0.0.1:42099/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3837 T3679 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3837 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920006 type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3838 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920006 type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3839 T3679 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4840 T3679 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50766_kbo%2Fzj
[junit4:junit4]   2> 4841 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920006 type:delete cxid:0x9 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:50766_kbo%2Fzj Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:50766_kbo%2Fzj
[junit4:junit4]   2> 4841 T3679 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50766_kbo%2Fzj
[junit4:junit4]   2> 4843 T3701 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> 4843 T3720 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 4843 T3707 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 4844 T3701 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 4869 T3721 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361623559197/collection1
[junit4:junit4]   2> 4869 T3721 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 4869 T3721 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 4869 T3721 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 4870 T3721 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-1361623559197/collection1/'
[junit4:junit4]   2> 4870 T3721 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361623559197/collection1/lib/README' to classloader
[junit4:junit4]   2> 4871 T3721 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361623559197/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 4891 T3721 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 4920 T3721 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 4921 T3721 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 4924 T3721 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 5191 T3702 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5191 T3702 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:47692/kbo/zj",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:47692_kbo%2Fzj",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "operation":"state"}
[junit4:junit4]   2> 5193 T3707 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 5193 T3701 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 5194 T3720 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 5262 T3721 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 5267 T3721 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 5269 T3721 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 5276 T3721 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5278 T3721 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5281 T3721 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5281 T3721 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5282 T3721 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361623559197/collection1/, dataDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty1/
[junit4:junit4]   2> 5282 T3721 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d0063
[junit4:junit4]   2> 5282 T3721 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 5283 T3721 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty1 forceNew:false
[junit4:junit4]   2> 5283 T3721 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty1
[junit4:junit4]   2> 5283 T3721 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty1/index/
[junit4:junit4]   2> 5283 T3721 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 5284 T3721 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty1/index forceNew:false
[junit4:junit4]   2> 5285 T3721 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@584bfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c62ed),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 5285 T3721 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 5285 T3721 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty1/index
[junit4:junit4]   2> 5286 T3721 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 5287 T3721 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 5287 T3721 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 5287 T3721 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 5288 T3721 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 5288 T3721 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 5288 T3721 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 5288 T3721 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 5289 T3721 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 5291 T3721 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 5293 T3721 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty1
[junit4:junit4]   2> 5293 T3721 oass.SolrIndexSearcher.<init> Opening Searcher@1862268 main
[junit4:junit4]   2> 5293 T3721 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty1/tlog
[junit4:junit4]   2> 5294 T3721 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 5294 T3721 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 5297 T3722 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1862268 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 5298 T3721 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 5298 T3721 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 6696 T3702 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6696 T3702 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50766/kbo/zj",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50766_kbo%2Fzj",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "operation":"state"}
[junit4:junit4]   2> 6696 T3702 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4]   2> 6696 T3702 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4]   2> 6827 T3720 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 6827 T3707 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 6827 T3701 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 7299 T3721 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 7299 T3721 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50766/kbo/zj collection:collection1 shard:shard2
[junit4:junit4]   2> 7300 T3721 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 7303 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920006 type:delete cxid:0x46 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 7304 T3721 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 7304 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920006 type:create cxid:0x47 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7305 T3721 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 7305 T3721 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 7306 T3721 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50766/kbo/zj/collection1/
[junit4:junit4]   2> 7306 T3721 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 7307 T3721 oasc.SyncStrategy.syncToMe http://127.0.0.1:50766/kbo/zj/collection1/ has no replicas
[junit4:junit4]   2> 7308 T3721 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50766/kbo/zj/collection1/
[junit4:junit4]   2> 7308 T3721 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 7310 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920006 type:create cxid:0x51 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8330 T3702 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8335 T3707 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 8335 T3720 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 8334 T3701 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 8363 T3721 oasc.ZkController.register We are http://127.0.0.1:50766/kbo/zj/collection1/ and leader is http://127.0.0.1:50766/kbo/zj/collection1/
[junit4:junit4]   2> 8363 T3721 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50766/kbo/zj
[junit4:junit4]   2> 8364 T3721 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 8364 T3721 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 8364 T3721 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 8365 T3721 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8366 T3679 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 8366 T3679 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 8367 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 8415 T3679 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 8416 T3679 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:56625
[junit4:junit4]   2> 8417 T3679 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 8417 T3679 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8417 T3679 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-1361623563837
[junit4:junit4]   2> 8418 T3679 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361623563837/solr.xml
[junit4:junit4]   2> 8418 T3679 oasc.CoreContainer.<init> New CoreContainer 27838292
[junit4:junit4]   2> 8418 T3679 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-1361623563837/'
[junit4:junit4]   2> 8419 T3679 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-1361623563837/'
[junit4:junit4]   2> 8432 T3679 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 8433 T3679 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 8433 T3679 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 8434 T3679 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 8434 T3679 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 8434 T3679 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 8434 T3679 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 8435 T3679 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 8435 T3679 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 8435 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 8441 T3679 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 8449 T3679 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:42099/solr
[junit4:junit4]   2> 8449 T3679 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 8450 T3679 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42099 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@2f63c
[junit4:junit4]   2> 8450 T3679 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8451 T3732 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42099. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 8451 T3732 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42099, initiating session
[junit4:junit4]   2> 8451 T3681 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:43715
[junit4:junit4]   2> 8451 T3681 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:43715
[junit4:junit4]   2> 8453 T3732 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42099, sessionid = 0x13d07169d920007, negotiated timeout = 20000
[junit4:junit4]   2> 8453 T3683 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d07169d920007 with negotiated timeout 20000 for client /127.0.0.1:43715
[junit4:junit4]   2> 8453 T3733 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f63c name:ZooKeeperConnection Watcher:127.0.0.1:42099 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8453 T3679 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8454 T3684 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d07169d920007
[junit4:junit4]   2> 8454 T3733 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 8454 T3681 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:43715 which had sessionid 0x13d07169d920007
[junit4:junit4]   2> 8454 T3679 oaz.ZooKeeper.close Session: 0x13d07169d920007 closed
[junit4:junit4]   2> 8455 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 8457 T3679 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42099/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@14e618b
[junit4:junit4]   2> 8458 T3734 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42099. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 8458 T3679 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8458 T3734 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42099, initiating session
[junit4:junit4]   2> 8458 T3681 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:43716
[junit4:junit4]   2> 8458 T3681 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:43716
[junit4:junit4]   2> 8459 T3683 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d07169d920008 with negotiated timeout 20000 for client /127.0.0.1:43716
[junit4:junit4]   2> 8459 T3734 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42099, sessionid = 0x13d07169d920008, negotiated timeout = 20000
[junit4:junit4]   2> 8459 T3735 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14e618b name:ZooKeeperConnection Watcher:127.0.0.1:42099/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8459 T3679 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8460 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920008 type:create cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8460 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920008 type:create cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8461 T3679 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9463 T3679 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56625_kbo%2Fzj
[junit4:junit4]   2> 9463 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920008 type:delete cxid:0x9 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:56625_kbo%2Fzj Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:56625_kbo%2Fzj
[junit4:junit4]   2> 9464 T3679 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56625_kbo%2Fzj
[junit4:junit4]   2> 9465 T3701 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 9465 T3720 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9465 T3735 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9466 T3720 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9465 T3707 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9466 T3707 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9466 T3701 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9471 T3736 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361623563837/collection1
[junit4:junit4]   2> 9471 T3736 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 9471 T3736 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 9471 T3736 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 9472 T3736 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-1361623563837/collection1/'
[junit4:junit4]   2> 9473 T3736 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361623563837/collection1/lib/README' to classloader
[junit4:junit4]   2> 9473 T3736 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361623563837/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 9492 T3736 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 9526 T3736 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 9527 T3736 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 9531 T3736 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 9841 T3702 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9841 T3702 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50766/kbo/zj",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50766_kbo%2Fzj",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "operation":"state"}
[junit4:junit4]   2> 9842 T3736 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 9843 T3701 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9843 T3707 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9843 T3720 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9843 T3735 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9850 T3736 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 9853 T3736 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 9860 T3736 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 9863 T3736 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 9867 T3736 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 9867 T3736 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 9868 T3736 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361623563837/collection1/, dataDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty2/
[junit4:junit4]   2> 9869 T3736 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d0063
[junit4:junit4]   2> 9869 T3736 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 9869 T3736 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty2 forceNew:false
[junit4:junit4]   2> 9870 T3736 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty2
[junit4:junit4]   2> 9870 T3736 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty2/index/
[junit4:junit4]   2> 9870 T3736 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 9871 T3736 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty2/index forceNew:false
[junit4:junit4]   2> 9872 T3736 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1e72ba6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@135d7fb),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9872 T3736 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 9873 T3736 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty2/index
[junit4:junit4]   2> 9874 T3736 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 9874 T3736 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 9875 T3736 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 9875 T3736 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 9875 T3736 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 9876 T3736 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 9876 T3736 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 9876 T3736 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 9876 T3736 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 9879 T3736 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 9881 T3736 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty2
[junit4:junit4]   2> 9881 T3736 oass.SolrIndexSearcher.<init> Opening Searcher@dc6564 main
[junit4:junit4]   2> 9881 T3736 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty2/tlog
[junit4:junit4]   2> 9882 T3736 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 9882 T3736 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 9885 T3737 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@dc6564 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 9886 T3736 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 9886 T3736 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 11346 T3702 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11347 T3702 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:56625/kbo/zj",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:56625_kbo%2Fzj",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "operation":"state"}
[junit4:junit4]   2> 11347 T3702 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 11347 T3702 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 11437 T3707 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 11437 T3735 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 11437 T3720 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 11437 T3701 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 11887 T3736 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 11887 T3736 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56625/kbo/zj collection:collection1 shard:shard1
[junit4:junit4]   2> 11888 T3736 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 11890 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920008 type:delete cxid:0x45 zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard1 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard1
[junit4:junit4]   2> 11891 T3736 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 11891 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920008 type:create cxid:0x46 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 11892 T3736 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 11892 T3736 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 11892 T3736 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:56625/kbo/zj/collection1/
[junit4:junit4]   2> 11892 T3736 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 11892 T3736 oasc.SyncStrategy.syncToMe http://127.0.0.1:56625/kbo/zj/collection1/ has no replicas
[junit4:junit4]   2> 11892 T3736 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:56625/kbo/zj/collection1/
[junit4:junit4]   2> 11893 T3736 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 11894 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920008 type:create cxid:0x4f zxid:0x82 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12940 T3702 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12977 T3707 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 12977 T3735 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 12977 T3720 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 12977 T3701 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 12997 T3736 oasc.ZkController.register We are http://127.0.0.1:56625/kbo/zj/collection1/ and leader is http://127.0.0.1:56625/kbo/zj/collection1/
[junit4:junit4]   2> 12997 T3736 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56625/kbo/zj
[junit4:junit4]   2> 12998 T3736 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 12998 T3736 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 12998 T3736 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 12999 T3736 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13000 T3679 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 13000 T3679 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 13001 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 13072 T3679 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 13074 T3679 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50041
[junit4:junit4]   2> 13074 T3679 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 13075 T3679 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 13075 T3679 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-1361623568473
[junit4:junit4]   2> 13076 T3679 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361623568473/solr.xml
[junit4:junit4]   2> 13076 T3679 oasc.CoreContainer.<init> New CoreContainer 9641442
[junit4:junit4]   2> 13076 T3679 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-1361623568473/'
[junit4:junit4]   2> 13077 T3679 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-1361623568473/'
[junit4:junit4]   2> 13090 T3679 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 13090 T3679 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 13090 T3679 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 13091 T3679 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 13091 T3679 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 13091 T3679 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 13092 T3679 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 13092 T3679 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 13092 T3679 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 13093 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 13098 T3679 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 13106 T3679 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:42099/solr
[junit4:junit4]   2> 13107 T3679 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 13107 T3679 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42099 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@166558d
[junit4:junit4]   2> 13108 T3747 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42099. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 13108 T3679 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 13108 T3681 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:43717
[junit4:junit4]   2> 13108 T3747 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42099, initiating session
[junit4:junit4]   2> 13109 T3681 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:43717
[junit4:junit4]   2> 13110 T3683 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d07169d920009 with negotiated timeout 20000 for client /127.0.0.1:43717
[junit4:junit4]   2> 13110 T3747 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42099, sessionid = 0x13d07169d920009, negotiated timeout = 20000
[junit4:junit4]   2> 13110 T3748 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@166558d name:ZooKeeperConnection Watcher:127.0.0.1:42099 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 13110 T3679 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 13111 T3684 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d07169d920009
[junit4:junit4]   2> 13111 T3681 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:43717 which had sessionid 0x13d07169d920009
[junit4:junit4]   2> 13111 T3748 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 13111 T3679 oaz.ZooKeeper.close Session: 0x13d07169d920009 closed
[junit4:junit4]   2> 13112 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 13114 T3679 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42099/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@afd27c
[junit4:junit4]   2> 13115 T3749 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42099. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 13114 T3679 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 13115 T3681 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:43718
[junit4:junit4]   2> 13115 T3749 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42099, initiating session
[junit4:junit4]   2> 13115 T3681 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:43718
[junit4:junit4]   2> 13116 T3683 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d07169d92000a with negotiated timeout 20000 for client /127.0.0.1:43718
[junit4:junit4]   2> 13116 T3749 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42099, sessionid = 0x13d07169d92000a, negotiated timeout = 20000
[junit4:junit4]   2> 13116 T3750 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@afd27c name:ZooKeeperConnection Watcher:127.0.0.1:42099/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 13116 T3679 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 13117 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d92000a type:create cxid:0x1 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 13117 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d92000a type:create cxid:0x2 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 13118 T3679 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 14120 T3679 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50041_kbo%2Fzj
[junit4:junit4]   2> 14121 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d92000a type:delete cxid:0x9 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:50041_kbo%2Fzj Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:50041_kbo%2Fzj
[junit4:junit4]   2> 14121 T3679 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50041_kbo%2Fzj
[junit4:junit4]   2> 14123 T3720 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 14123 T3735 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 14123 T3701 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14123 T3701 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 14123 T3707 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14124 T3707 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 14124 T3750 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14124 T3720 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14125 T3735 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14129 T3751 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361623568473/collection1
[junit4:junit4]   2> 14130 T3751 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 14130 T3751 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 14130 T3751 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 14131 T3751 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-1361623568473/collection1/'
[junit4:junit4]   2> 14131 T3751 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361623568473/collection1/lib/README' to classloader
[junit4:junit4]   2> 14132 T3751 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361623568473/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 14161 T3751 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 14202 T3751 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 14203 T3751 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 14207 T3751 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 14481 T3702 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14482 T3702 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:56625/kbo/zj",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:56625_kbo%2Fzj",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "operation":"state"}
[junit4:junit4]   2> 14484 T3707 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 14484 T3735 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 14484 T3720 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 14485 T3701 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 14485 T3750 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 14559 T3751 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 14564 T3751 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 14566 T3751 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 14573 T3751 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14575 T3751 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14577 T3751 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14578 T3751 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14578 T3751 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361623568473/collection1/, dataDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3/
[junit4:junit4]   2> 14578 T3751 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d0063
[junit4:junit4]   2> 14579 T3751 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 14579 T3751 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3 forceNew:false
[junit4:junit4]   2> 14580 T3751 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3
[junit4:junit4]   2> 14580 T3751 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3/index/
[junit4:junit4]   2> 14580 T3751 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 14580 T3751 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3/index forceNew:false
[junit4:junit4]   2> 14581 T3751 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@a71f4d lockFactory=org.apache.lucene.store.NativeFSLockFactory@1227106),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 14581 T3751 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 14581 T3751 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3/index
[junit4:junit4]   2> 14582 T3751 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 14582 T3751 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 14583 T3751 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 14583 T3751 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 14583 T3751 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 14583 T3751 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 14584 T3751 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 14584 T3751 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 14584 T3751 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 14586 T3751 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 14588 T3751 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3
[junit4:junit4]   2> 14588 T3751 oass.SolrIndexSearcher.<init> Opening Searcher@a61bb8 main
[junit4:junit4]   2> 14588 T3751 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3/tlog
[junit4:junit4]   2> 14589 T3751 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 14589 T3751 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 14591 T3752 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@a61bb8 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 14592 T3751 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 14592 T3751 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 15987 T3702 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15988 T3702 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50041/kbo/zj",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50041_kbo%2Fzj",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "operation":"state"}
[junit4:junit4]   2> 15988 T3702 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 15988 T3702 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4]   2> 16049 T3720 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 16049 T3735 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 16050 T3750 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 16050 T3701 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 16049 T3707 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 16593 T3751 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 16593 T3751 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50041/kbo/zj collection:collection1 shard:shard2
[junit4:junit4]   2> 16595 T3751 oasc.ZkController.register We are http://127.0.0.1:50041/kbo/zj/collection1/ and leader is http://127.0.0.1:50766/kbo/zj/collection1/
[junit4:junit4]   2> 16595 T3751 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50041/kbo/zj
[junit4:junit4]   2> 16596 T3751 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 16596 T3751 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C308 name=collection1 org.apache.solr.core.SolrCore@30fd83 url=http://127.0.0.1:50041/kbo/zj/collection1 node=127.0.0.1:50041_kbo%2Fzj C308_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:50041/kbo/zj, core=collection1, collection=collection1, node_name=127.0.0.1:50041_kbo%2Fzj, roles=null, shard=null}
[junit4:junit4]   2> 16596 T3753 C308 P50041 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 16596 T3751 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16597 T3753 C308 P50041 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 16597 T3753 C308 P50041 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 16597 T3753 C308 P50041 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 16597 T3679 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 16598 T3753 C308 P50041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 16598 T3679 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 16598 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 16673 T3679 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 16675 T3679 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:59673
[junit4:junit4]   2> 16675 T3679 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 16676 T3679 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 16676 T3679 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-1361623572070
[junit4:junit4]   2> 16676 T3679 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361623572070/solr.xml
[junit4:junit4]   2> 16677 T3679 oasc.CoreContainer.<init> New CoreContainer 21604146
[junit4:junit4]   2> 16677 T3679 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-1361623572070/'
[junit4:junit4]   2> 16677 T3679 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-1361623572070/'
[junit4:junit4]   2> 16696 T3679 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 16696 T3679 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 16697 T3679 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 16697 T3679 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 16697 T3679 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 16698 T3679 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 16698 T3679 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 16698 T3679 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 16699 T3679 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 16699 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 16707 T3679 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 16719 T3679 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:42099/solr
[junit4:junit4]   2> 16720 T3679 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 16720 T3679 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42099 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@a9fc14
[junit4:junit4]   2> 16721 T3763 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42099. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 16721 T3679 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 16722 T3763 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42099, initiating session
[junit4:junit4]   2> 16722 T3681 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:43720
[junit4:junit4]   2> 16722 T3681 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:43720
[junit4:junit4]   2> 16723 T3683 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d07169d92000b with negotiated timeout 20000 for client /127.0.0.1:43720
[junit4:junit4]   2> 16723 T3763 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42099, sessionid = 0x13d07169d92000b, negotiated timeout = 20000
[junit4:junit4]   2> 16723 T3764 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a9fc14 name:ZooKeeperConnection Watcher:127.0.0.1:42099 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 16723 T3679 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 16724 T3684 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d07169d92000b
[junit4:junit4]   2> 16724 T3764 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 16724 T3681 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:43720 which had sessionid 0x13d07169d92000b
[junit4:junit4]   2> 16724 T3679 oaz.ZooKeeper.close Session: 0x13d07169d92000b closed
[junit4:junit4]   2> 16725 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 16727 T3679 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42099/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@ae2673
[junit4:junit4]   2> 16728 T3679 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 16729 T3765 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42099. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 16730 T3765 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42099, initiating session
[junit4:junit4]   2> 16730 T3681 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:43721
[junit4:junit4]   2> 16730 T3681 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:43721
[junit4:junit4]   2> 16731 T3683 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d07169d92000c with negotiated timeout 20000 for client /127.0.0.1:43721
[junit4:junit4]   2> 16731 T3765 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42099, sessionid = 0x13d07169d92000c, negotiated timeout = 20000
[junit4:junit4]   2> 16731 T3766 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ae2673 name:ZooKeeperConnection Watcher:127.0.0.1:42099/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 16731 T3679 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 16732 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d92000c type:create cxid:0x1 zxid:0xa2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 16733 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d92000c type:create cxid:0x2 zxid:0xa3 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 16734 T3679 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 17552 T3702 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 17553 T3702 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50041/kbo/zj",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50041_kbo%2Fzj",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "operation":"state"}
[junit4:junit4]   2> 17557 T3750 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17557 T3707 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17557 T3766 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17557 T3720 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17557 T3701 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17557 T3735 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17736 T3679 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59673_kbo%2Fzj
[junit4:junit4]   2> 17736 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d92000c type:delete cxid:0xb zxid:0xa8 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:59673_kbo%2Fzj Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:59673_kbo%2Fzj
[junit4:junit4]   2> 17737 T3679 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59673_kbo%2Fzj
[junit4:junit4]   2> 17738 T3720 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17738 T3735 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17738 T3766 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17739 T3701 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17738 T3750 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17739 T3707 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17739 T3707 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 17739 T3701 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 17740 T3750 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17740 T3720 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17740 T3766 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17740 T3735 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17745 T3767 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361623572070/collection1
[junit4:junit4]   2> 17745 T3767 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 17746 T3767 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 17746 T3767 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 17748 T3767 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-1361623572070/collection1/'
[junit4:junit4]   2> 17748 T3767 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361623572070/collection1/lib/README' to classloader
[junit4:junit4]   2> 17749 T3767 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361623572070/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 17782 T3767 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 17819 T3767 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 17821 T3767 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 17824 T3767 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 18161 T3767 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 18168 T3767 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 18171 T3767 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 18179 T3767 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 18182 T3767 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 18185 T3767 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 18186 T3767 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 18187 T3767 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361623572070/collection1/, dataDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4/
[junit4:junit4]   2> 18187 T3767 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d0063
[junit4:junit4]   2> 18188 T3767 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 18188 T3767 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4 forceNew:false
[junit4:junit4]   2> 18188 T3767 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4
[junit4:junit4]   2> 18189 T3767 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4/index/
[junit4:junit4]   2> 18189 T3767 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 18189 T3767 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4/index forceNew:false
[junit4:junit4]   2> 18190 T3767 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@c6c55f lockFactory=org.apache.lucene.store.NativeFSLockFactory@eec24e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 18190 T3767 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 18191 T3767 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4/index
[junit4:junit4]   2> 18192 T3767 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 18192 T3767 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 18193 T3767 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 18193 T3767 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 18194 T3767 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 18194 T3767 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 18194 T3767 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 18194 T3767 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 18195 T3767 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 18198 T3767 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 18200 T3767 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4
[junit4:junit4]   2> 18201 T3767 oass.SolrIndexSearcher.<init> Opening Searcher@1f6b012 main
[junit4:junit4]   2> 18201 T3767 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4/tlog
[junit4:junit4]   2> 18202 T3767 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 18202 T3767 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 18205 T3768 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1f6b012 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 18206 T3767 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 18207 T3767 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 19061 T3702 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19061 T3702 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:59673/kbo/zj",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:59673_kbo%2Fzj",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "operation":"state"}
[junit4:junit4]   2> 19062 T3702 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 19062 T3702 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 19065 T3766 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> 19065 T3750 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> 19065 T3701 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> 19065 T3735 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> 19065 T3707 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> 19065 T3720 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> 19208 T3767 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 19208 T3767 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:59673/kbo/zj collection:collection1 shard:shard1
[junit4:junit4]   2> 19210 T3767 oasc.ZkController.register We are http://127.0.0.1:59673/kbo/zj/collection1/ and leader is http://127.0.0.1:56625/kbo/zj/collection1/
[junit4:junit4]   2> 19210 T3767 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:59673/kbo/zj
[junit4:junit4]   2> 19210 T3767 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 19211 T3767 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C309 name=collection1 org.apache.solr.core.SolrCore@81c759 url=http://127.0.0.1:59673/kbo/zj/collection1 node=127.0.0.1:59673_kbo%2Fzj C309_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:59673/kbo/zj, core=collection1, collection=collection1, node_name=127.0.0.1:59673_kbo%2Fzj, roles=null, shard=null}
[junit4:junit4]   2> 19211 T3769 C309 P59673 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 19211 T3767 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19211 T3769 C309 P59673 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 19211 T3769 C309 P59673 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 19212 T3769 C309 P59673 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 19212 T3679 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 19213 T3679 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 19213 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 19220 T3679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19221 T3769 C309 P59673 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 19221 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 19225 T3713 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-1361623559197/unloadcollection1
[junit4:junit4]   2> 19226 T3713 oasc.ZkController.createCollectionZkNode Check for collection zkNode:unloadcollection
[junit4:junit4]   2> 19226 T3713 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:unloadcollection
[junit4:junit4]   2> 19227 T3713 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4]   2> 19227 T3713 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4]   2> 19228 T3713 oascc.SolrZkClient.makePath makePath: /collections/unloadcollection
[junit4:junit4]   2> 19229 T3713 oasc.ZkController.readConfigName Load collection config from:/collections/unloadcollection
[junit4:junit4]   2> 19230 T3713 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-1361623559197/unloadcollection1/'
[junit4:junit4]   2> 19268 T3713 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 19308 T3713 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 19309 T3713 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 19312 T3713 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2>  C308_STATE=coll:collection1 core:collection1 props:{state=recovering, base_url=http://127.0.0.1:50041/kbo/zj, core=collection1, collection=collection1, node_name=127.0.0.1:50041_kbo%2Fzj, roles=null, shard=shard2}
[junit4:junit4]   2> 19603 T3753 C308 P50041 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:50766/kbo/zj/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 19603 T3753 C308 P50041 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:50041/kbo/zj START replicas=[http://127.0.0.1:50766/kbo/zj/collection1/] nUpdates=100
[junit4:junit4]   2> 19603 T3753 C308 P50041 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 19604 T3753 C308 P50041 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 19604 T3753 C308 P50041 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 19604 T3753 C308 P50041 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 19604 T3753 C308 P50041 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 19604 T3753 C308 P50041 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:50766/kbo/zj/collection1/. core=collection1
[junit4:junit4]   2> 19605 T3753 C308 P50041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C310 name=collection1 org.apache.solr.core.SolrCore@b8c4f4 url=http://127.0.0.1:50766/kbo/zj/collection1 node=127.0.0.1:50766_kbo%2Fzj C310_STATE=coll:collection1 core:collection1 props:{state=active, base_url=http://127.0.0.1:50766/kbo/zj, core=collection1, collection=collection1, node_name=127.0.0.1:50766_kbo%2Fzj, roles=null, shard=shard2, leader=true}
[junit4:junit4]   2> 19609 T3714 C310 P50766 REQ /get {version=2&wt=javabin&getVersions=100&distrib=false&qt=/get} status=0 QTime=0 
[junit4:junit4]   2> 19611 T3715 C310 P50766 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 19611 T3715 C310 P50766 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty1
[junit4:junit4]   2> 19612 T3715 C310 P50766 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@584bfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c62ed),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 19612 T3715 C310 P50766 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 19613 T3715 C310 P50766 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@584bfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c62ed),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@584bfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c62ed),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 19613 T3715 C310 P50766 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 19613 T3715 C310 P50766 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty1
[junit4:junit4]   2> 19614 T3715 C310 P50766 oass.SolrIndexSearcher.<init> Opening Searcher@150a5b9 realtime
[junit4:junit4]   2> 19614 T3715 C310 P50766 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 19614 T3715 C310 P50766 /update {version=2&commit=true&wt=javabin&softCommit=false&commit_end_point=true&waitSearcher=true&openSearcher=false} {commit=} 0 3
[junit4:junit4]   2> 19615 T3753 C308 P50041 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 19615 T3753 C308 P50041 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 19619 T3715 C310 P50766 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 19619 T3715 C310 P50766 REQ /replication {command=indexversion&version=2&wt=javabin&qt=/replication} status=0 QTime=3 
[junit4:junit4]   2> 19620 T3753 C308 P50041 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 19620 T3753 C308 P50041 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 19620 T3753 C308 P50041 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 19622 T3716 C310 P50766 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty1
[junit4:junit4]   2> 19622 T3716 C310 P50766 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty1/index
[junit4:junit4]   2> 19622 T3716 C310 P50766 REQ /replication {command=filelist&version=2&generation=2&wt=javabin&qt=/replication} status=0 QTime=0 
[junit4:junit4]   2> 19623 T3753 C308 P50041 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 19624 T3753 C308 P50041 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3/index.20130223084615091 forceNew:false
[junit4:junit4]   2> 19624 T3753 C308 P50041 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3
[junit4:junit4]   2> 19624 T3753 C308 P50041 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@1057740 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c175d) fullCopy=true
[junit4:junit4]   2> 19626 T3714 C310 P50766 REQ /replication {command=filecontent&checksum=true&generation=2&wt=filestream&file=segments_2&qt=/replication} status=0 QTime=0 
[junit4:junit4]   2> 19627 T3753 C308 P50041 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3/index
[junit4:junit4]   2> 19628 T3753 C308 P50041 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 19628 T3753 C308 P50041 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130223084615091
[junit4:junit4]   2> 19628 T3753 C308 P50041 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3
[junit4:junit4]   2> 19629 T3753 C308 P50041 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3
[junit4:junit4]   2> 19629 T3753 C308 P50041 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3/index/ new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3/index.20130223084615091
[junit4:junit4]   2> 19630 T3753 C308 P50041 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1057740 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c175d),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 19630 T3753 C308 P50041 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 19630 T3753 C308 P50041 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3
[junit4:junit4]   2> 19631 T3753 C308 P50041 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3
[junit4:junit4]   2> 19631 T3753 C308 P50041 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 19631 T3753 C308 P50041 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 19631 T3753 C308 P50041 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 19632 T3753 C308 P50041 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3/index.20130223084615091
[junit4:junit4]   2> 19632 T3753 C308 P50041 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3
[junit4:junit4]   2> 19633 T3753 C308 P50041 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1057740 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c175d),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 19633 T3753 C308 P50041 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 19633 T3753 C308 P50041 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 19634 T3753 C308 P50041 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3
[junit4:junit4]   2> 19634 T3753 C308 P50041 oass.SolrIndexSearcher.<init> Opening Searcher@17278a9 main
[junit4:junit4]   2> 19635 T3752 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@17278a9 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 19635 T3752 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3/index
[junit4:junit4]   2> 19635 T3753 C308 P50041 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3/index.20130223084615091
[junit4:junit4]   2> 19635 T3753 C308 P50041 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty3/index
[junit4:junit4]   2> 19636 T3753 C308 P50041 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 19636 T3753 C308 P50041 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 19636 T3753 C308 P50041 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 19636 T3753 C308 P50041 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 19637 T3753 C308 P50041 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 19711 T3713 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 19718 T3713 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 19722 T3713 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 19730 T3713 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 19736 T3713 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 19739 T3713 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 19740 T3713 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 19742 T3713 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-1361623559197/unloadcollection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361623555471/1361623574692unloadcollection1_1n/
[junit4:junit4]   2> 19742 T3713 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d0063
[junit4:junit4]   2> 19742 T3713 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 19743 T3713 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361623555471/1361623574692unloadcollection1_1n forceNew:false
[junit4:junit4]   2> 19744 T3713 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361623555471/1361623574692unloadcollection1_1n
[junit4:junit4]   2> 19744 T3713 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-1361623555471/1361623574692unloadcollection1_1n/index/
[junit4:junit4]   2> 19745 T3713 oasc.SolrCore.initIndex WARNING [unloadcollection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361623555471/1361623574692unloadcollection1_1n/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 19745 T3713 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361623555471/1361623574692unloadcollection1_1n/index forceNew:false
[junit4:junit4]   2> 19746 T3713 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@194388 lockFactory=org.apache.lucene.store.NativeFSLockFactory@15b97c6),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 19746 T3713 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 19747 T3713 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361623555471/1361623574692unloadcollection1_1n/index
[junit4:junit4]   2> 19749 T3713 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 19749 T3713 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 19750 T3713 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 19750 T3713 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 19751 T3713 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 19751 T3713 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 19751 T3713 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 19752 T3713 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 19752 T3713 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 19755 T3713 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 19759 T3713 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361623555471/1361623574692unloadcollection1_1n
[junit4:junit4]   2> 19759 T3713 oass.SolrIndexSearcher.<init> Opening Searcher@18ca73c main
[junit4:junit4]   2> 19760 T3713 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361623555471/1361623574692unloadcollection1_1n/tlog
[junit4:junit4]   2> 19760 T3713 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 19761 T3713 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 19763 T3713 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361623555471/1361623574692unloadcollection1_1n
[junit4:junit4]   2> 19765 T3713 oasc.ZkController.publish publishing core=unloadcollection1 state=down
[junit4:junit4]   2> 19770 T3772 oasc.SolrCore.registerSearcher [unloadcollection1] Registered new searcher Searcher@18ca73c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 20568 T3702 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20568 T3702 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:59673/kbo/zj",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:59673_kbo%2Fzj",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "operation":"state"}
[junit4:junit4]   2> 20573 T3702 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50041/kbo/zj",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50041_kbo%2Fzj",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "operation":"state"}
[junit4:junit4]   2> 20574 T3702 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50766/kbo/zj",
[junit4:junit4]   2> 	  "core":"unloadcollection1",
[junit4:junit4]   2> 	  "collection":"unloadcollection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50766_kbo%2Fzj",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "operation":"state"}
[junit4:junit4]   2> 20575 T3702 oasc.Overseer$ClusterStateUpdater.createCollection Create collection unloadcollection with numShards 1
[junit4:junit4]   2> 20575 T3702 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 20578 T3766 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> 20578 T3701 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> 20578 T3720 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> 20578 T3707 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> 20578 T3735 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> 20578 T3750 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> 20770 T3713 oasc.CoreContainer.registerCore registering core: unloadcollection1
[junit4:junit4]   2> 20771 T3713 oasc.ZkController.register Register replica - core:unloadcollection1 address:http://127.0.0.1:50766/kbo/zj collection:unloadcollection shard:shard1
[junit4:junit4]   2> 20772 T3713 oascc.SolrZkClient.makePath makePath: /collections/unloadcollection/leader_elect/shard1/election
[junit4:junit4]   2> 20776 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920006 type:delete cxid:0xa6 zxid:0xc3 txntype:-1 reqpath:n/a Error Path:/solr/collections/unloadcollection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/unloadcollection/leaders
[junit4:junit4]   2> 20777 T3713 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 20778 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920006 type:create cxid:0xa7 zxid:0xc4 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 20779 T3713 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 20779 T3713 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 20780 T3713 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50766/kbo/zj/unloadcollection1/
[junit4:junit4]   2> 20780 T3713 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 20781 T3713 oasc.SyncStrategy.syncToMe http://127.0.0.1:50766/kbo/zj/unloadcollection1/ has no replicas
[junit4:junit4]   2> 20781 T3713 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50766/kbo/zj/unloadcollection1/
[junit4:junit4]   2> 20781 T3713 oascc.SolrZkClient.makePath makePath: /collections/unloadcollection/leaders/shard1
[junit4:junit4]   2> 20804 T3684 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d07169d920006 type:create cxid:0xb1 zxid:0xc8 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 22083 T3702 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22088 T3707 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> 22088 T3750 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> 22089 T3701 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> 22089 T3735 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> 22089 T3720 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> 22088 T3766 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> 22108 T3713 oasc.ZkController.register We are http://127.0.0.1:50766/kbo/zj/unloadcollection1/ and leader is http://127.0.0.1:50766/kbo/zj/unloadcollection1/
[junit4:junit4]   2> 22108 T3713 oasc.ZkController.register No LogReplay needed for core=unloadcollection1 baseURL=http://127.0.0.1:50766/kbo/zj
[junit4:junit4]   2> 22109 T3713 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 22109 T3713 oasc.ZkController.publish publishing core=unloadcollection1 state=active
[junit4:junit4]   2> 22110 T3713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22111 T3713 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-1361623559197/solr.xml
[junit4:junit4]   2> 22116 T3713 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-1361623559197/solr.xml
[junit4:junit4]   2> 22117 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 22118 T3679 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42099/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@d78006
[junit4:junit4]   2> 22119 T3679 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 22119 T3773 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42099. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 22119 T3773 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42099, initiating session
[junit4:junit4]   2> 22119 T3681 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:43728
[junit4:junit4]   2> 22120 T3681 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:43728
[junit4:junit4]   2> 22120 T3683 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d07169d92000d with negotiated timeout 10000 for client /127.0.0.1:43728
[junit4:junit4]   2> 22120 T3773 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42099, sessionid = 0x13d07169d92000d, negotiated timeout = 10000
[junit4:junit4]   2> 22121 T3774 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d78006 name:ZooKeeperConnection Watcher:127.0.0.1:42099/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 22121 T3679 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 22121 T3679 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 22123 T3679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22124 T3679 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 22126 T3731 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-1361623563837/unloadcollection2
[junit4:junit4]   2> 22127 T3731 oasc.ZkController.createCollectionZkNode Check for collection zkNode:unloadcollection
[junit4:junit4]   2> 22127 T3731 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 22127 T3731 oasc.ZkController.readConfigName Load collection config from:/collections/unloadcollection
[junit4:junit4]   2> 22129 T3731 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-1361623563837/unloadcollection2/'
[junit4:junit4]   2> 22151 T3731 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 22178 T3731 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 22179 T3731 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 22182 T3731 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 22513 T3731 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 22520 T3731 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 22524 T3731 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 22535 T3731 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 22538 T3731 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 22541 T3731 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 22542 T3731 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 22543 T3731 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-1361623563837/unloadcollection2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361623555471/1361623577594unloadcollection1_2n/
[junit4:junit4]   2> 22543 T3731 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@17d0063
[junit4:junit4]   2> 22544 T3731 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 22545 T3731 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361623555471/1361623577594unloadcollection1_2n forceNew:false
[junit4:junit4]   2> 22545 T3731 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361623555471/1361623577594unloadcollection1_2n
[junit4:junit4]   2> 22545 T3731 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-1361623555471/1361623577594unloadcollection1_2n/index/
[junit4:junit4]   2> 22546 T3731 oasc.SolrCore.initIndex WARNING [unloadcollection2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361623555471/1361623577594unloadcollection1_2n/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 22547 T3731 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361623555471/1361623577594unloadcollection1_2n/index forceNew:false
[junit4:junit4]   2> 22548 T3731 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@c028b9 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2f7676),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 22548 T3731 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 22549 T3731 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361623555471/1361623577594unloadcollection1_2n/index
[junit4:junit4]   2> 22550 T3731 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 22551 T3731 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 22551 T3731 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 22552 T3731 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 22552 T3731 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 22553 T3731 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 22553 T3731 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 22553 T3731 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 22554 T3731 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 22557 T3731 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 22559 T3731 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361623555471/1361623577594unloadcollection1_2n
[junit4:junit4]   2> 22559 T3731 oass.SolrIndexSearcher.<init> Opening Searcher@17f62f main
[junit4:junit4]   2> 22560 T3731 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361623555471/1361623577594unloadcollection1_2n/tlog
[junit4:junit4]   2> 22560 T3731 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 22561 T3731 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 22563 T3731 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361623555471/1361623577594unloadcollection1_2n
[junit4:junit4]   2> 22564 T3775 oasc.SolrCore.registerSearcher [unloadcollection2] Registered new searcher Searcher@17f62f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 22564 T3731 oasc.ZkController.publish publishing core=unloadcollection2 state=down
[junit4:junit4]   2> 22564 T3731 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2>  C309_STATE=coll:collection1 core:collection1 props:{state=recovering, base_url=http://127.0.0.1:59673/kbo/zj, core=collection1, collection=collection1, node_name=127.0.0.1:59673_kbo%2Fzj, roles=null, shard=shard1}
[junit4:junit4]   2> 23227 T3769 C309 P59673 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:56625/kbo/zj/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 23227 T3769 C309 P59673 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:59673/kbo/zj START replicas=[http://127.0.0.1:56625/kbo/zj/collection1/] nUpdates=100
[junit4:junit4]   2> 23228 T3769 C309 P59673 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 23228 T3769 C309 P59673 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 23228 T3769 C309 P59673 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 23228 T3769 C309 P59673 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 23228 T3769 C309 P59673 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 23229 T3769 C309 P59673 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:56625/kbo/zj/collection1/. core=collection1
[junit4:junit4]   2> 23229 T3769 C309 P59673 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C311 name=collection1 org.apache.solr.core.SolrCore@849f28 url=http://127.0.0.1:56625/kbo/zj/collection1 node=127.0.0.1:56625_kbo%2Fzj C311_STATE=coll:collection1 core:collection1 props:{state=active, base_url=http://127.0.0.1:56625/kbo/zj, core=collection1, collection=collection1, node_name=127.0.0.1:56625_kbo%2Fzj, roles=null, shard=shard1, leader=true}
[junit4:junit4]   2> 23233 T3728 C311 P56625 REQ /get {version=2&wt=javabin&getVersions=100&distrib=false&qt=/get} status=0 QTime=0 
[junit4:junit4]   2> 23234 T3730 C311 P56625 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 23235 T3730 C311 P56625 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty2
[junit4:junit4]   2> 23235 T3730 C311 P56625 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1e72ba6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@135d7fb),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 23236 T3730 C311 P56625 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 23236 T3730 C311 P56625 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1e72ba6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@135d7fb),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1e72ba6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@135d7fb),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 23237 T3730 C311 P56625 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 23237 T3730 C311 P56625 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty2
[junit4:junit4]   2> 23238 T3730 C311 P56625 oass.SolrIndexSearcher.<init> Opening Searcher@1856466 realtime
[junit4:junit4]   2> 23238 T3730 C311 P56625 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 23238 T3730 C311 P56625 /update {version=2&commit=true&wt=javabin&softCommit=false&commit_end_point=true&waitSearcher=true&openSearcher=false} {commit=} 0 4
[junit4:junit4]   2> 23239 T3769 C309 P59673 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 23239 T3769 C309 P59673 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 23241 T3729 C311 P56625 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 23242 T3729 C311 P56625 REQ /replication {command=indexversion&version=2&wt=javabin&qt=/replication} status=0 QTime=1 
[junit4:junit4]   2> 23248 T3769 C309 P59673 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 23248 T3769 C309 P59673 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 23248 T3769 C309 P59673 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 23250 T3730 C311 P56625 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty2
[junit4:junit4]   2> 23251 T3730 C311 P56625 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty2/index
[junit4:junit4]   2> 23251 T3730 C311 P56625 REQ /replication {command=filelist&version=2&generation=2&wt=javabin&qt=/replication} status=0 QTime=1 
[junit4:junit4]   2> 23252 T3769 C309 P59673 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 23252 T3769 C309 P59673 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4/index.20130223084618720 forceNew:false
[junit4:junit4]   2> 23253 T3769 C309 P59673 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4
[junit4:junit4]   2> 23253 T3769 C309 P59673 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@1298269 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1565558) fullCopy=true
[junit4:junit4]   2> 23255 T3728 C311 P56625 REQ /replication {command=filecontent&checksum=true&generation=2&wt=filestream&file=segments_2&qt=/replication} status=0 QTime=0 
[junit4:junit4]   2> 23256 T3769 C309 P59673 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4/index
[junit4:junit4]   2> 23256 T3769 C309 P59673 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 23257 T3769 C309 P59673 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130223084618720
[junit4:junit4]   2> 23257 T3769 C309 P59673 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4
[junit4:junit4]   2> 23257 T3769 C309 P59673 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4
[junit4:junit4]   2> 23258 T3769 C309 P59673 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4/index/ new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4/index.20130223084618720
[junit4:junit4]   2> 23259 T3769 C309 P59673 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1298269 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1565558),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 23259 T3769 C309 P59673 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 23259 T3769 C309 P59673 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4
[junit4:junit4]   2> 23260 T3769 C309 P59673 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4
[junit4:junit4]   2> 23260 T3769 C309 P59673 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 23260 T3769 C309 P59673 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 23260 T3769 C309 P59673 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 23261 T3769 C309 P59673 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4/index.20130223084618720
[junit4:junit4]   2> 23261 T3769 C309 P59673 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4
[junit4:junit4]   2> 23262 T3769 C309 P59673 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1298269 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1565558),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 23262 T3769 C309 P59673 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 23263 T3769 C309 P59673 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 23263 T3769 C309 P59673 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4
[junit4:junit4]   2> 23263 T3769 C309 P59673 oass.SolrIndexSearcher.<init> Opening Searcher@13b9869 main
[junit4:junit4]   2> 23264 T3768 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@13b9869 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 23264 T3768 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4/index
[junit4:junit4]   2> 23264 T3769 C309 P59673 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4/index.20130223084618720
[junit4:junit4]   2> 23264 T3769 C309 P59673 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361623555471/jetty4/index
[junit4:junit4]   2> 23264 T3769 C309 P59673 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 23265 T3769 C309 P59673 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 23265 T3769 C309 P59673 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 23265 T3769 C309 P59673 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 23275 T3769 C309 P59673 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 23592 T3702 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 23593 T3702 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50766/kbo/zj",
[junit4:junit4]   2> 	  "core":"unloadcollection1",
[junit4:junit4]   2> 	  "collection":"unloadcollection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50766_kbo%2Fzj",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "operation":"state"}
[junit4:junit4]   2> 23595 T3702 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:56625/kbo/zj",
[junit4:junit4]   2> 	  "core":"unloadcollection2",
[junit4:junit4]   2> 	  "collection":"unloadcollection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:56625_kbo%2Fzj",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "operation":"state"}
[junit4:junit4]   2> 23595 T3702 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4]   2> 23595 T3702 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 23597 T3702 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:59673/kbo/zj",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:59673_kbo%2Fzj",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "operation":"state"}
[junit4:junit4]   2> 23608 T3701 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> 23609 T3766 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> 23609 T3750 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> 23609 T3774 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> 23609 T3707 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> 23608 T3735 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> 23608 T3720 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> 24578 T3731 oasc.CoreContainer.registerCore registering core: unloadcollection2
[junit4:junit4]   2> 24578 T3731 oasc.ZkController.register Register replica - core:unloadcollection2 address:http://127.0.0.1:56625/kbo/zj collection:unloadcollection shard:shard1
[junit4:junit4]   2> 24580 T3731 oasc.ZkController.register We are http://127.0.0.1:56625/kbo/zj/unloadcollection2/ and leader is http://127.0.0.1:50766/kbo/zj/unloadcollection1/
[junit4:junit4]   2> 24581 T3731 oasc.ZkController.register No LogReplay needed for core=unloadcollection2 baseURL=http://127.0.0.1:56625/kbo/zj
[junit4:junit4]   2> 24581 T3731 oasc.ZkController.checkRecovery Core needs to recover:unloadcollection2
[junit4:junit4]   2> 24581 T3731 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C312 name=unloadcollection2 org.apache.solr.core.SolrCore@6fcca9 url=http://127.0.0.1:56625/kbo/zj/unloadcollection2 node=127.0.0.1:56625_kbo%2Fzj C312_STATE=coll:unloadcollection core:unloadcollection2 props:{state=down, base_url=http://127.0.0.1:56625/kbo/zj, core=unloadcollection2, collection=unloadcollection, node_name=127.0.0.1:56625_kbo%2Fzj, roles=null, shard=null}
[junit4:junit4]   2> 24581 T3778 C312 P56625 oasc.RecoveryStrategy.run Starting recovery process.  core=unloadcollection2 recoveringAfterStartup=true
[junit4:junit4]   2> 24582 T3778 C312 P56625 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit

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

 > 	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> 150932 T3679 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> 150940 T3678 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4]   2> 151532 T3682 oazs.SessionTrackerImpl.run SessionTrackerImpl exited loop!
[junit4:junit4]   2> NOTE: test params are: codec=Lucene42: {range_facet_sl=PostingsFormat(name=Memory doPackFST= false), id=PostingsFormat(name=SimpleText), timestamp=PostingsFormat(name=NestedPulsing), a_si=PostingsFormat(name=TestBloomFilteredLucene41Postings), _version_=PostingsFormat(name=NestedPulsing), range_facet_si=PostingsFormat(name=TestBloomFilteredLucene41Postings), range_facet_l=PostingsFormat(name=NestedPulsing), text=PostingsFormat(name=Memory doPackFST= false), intDefault=PostingsFormat(name=NestedPulsing), multiDefault=PostingsFormat(name=TestBloomFilteredLucene41Postings), a_t=PostingsFormat(name=NestedPulsing), other_tl1=PostingsFormat(name=NestedPulsing)}, docValues:{timestamp=DocValuesFormat(name=SimpleText)}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=ar_JO, timezone=America/Antigua
[junit4:junit4]   2> NOTE: Linux 3.2.0-38-generic i386/Oracle Corporation 1.8.0-ea (32-bit)/cpus=8,threads=1,free=171612048,total=315097088
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TermVectorComponentDistributedTest, SpellingQueryConverterTest, TestFastWriter, TestFuzzyAnalyzedSuggestions, StandardRequestHandlerTest, FullSolrCloudDistribCmdsTest, PrimUtilsTest, TestCSVLoader, RAMDirectoryFactoryTest, TestBM25SimilarityFactory, TestReload, TestSolr4Spatial, FieldMutatingUpdateProcessorTest, TestFoldingMultitermQuery, TestSolrXMLSerializer, SuggesterTest, TestLRUCache, TestCharFilters, ShowFileRequestHandlerTest, TestRemoteStreaming, ExternalFileFieldSortTest, TestWriterPerf, SolrInfoMBeanTest, TestSurroundQueryParser, ClusterStateUpdateTest, UpdateParamsTest, ZkCLITest, TestPropInjectDefaults, StatelessScriptUpdateProcessorFactoryTest, TestReplicationHandler, SolrIndexConfigTest, TestMultiCoreConfBootstrap, LukeRequestHandlerTest, IndexSchemaTest, XmlUpdateRequestHandlerTest, ZkSolrClientTest, TestCSVResponseWriter, XsltUpdateRequestHandlerTest, OutputWriterTest, TestRealTimeGet, TestUtils, TestReversedWildcardFilterFactory, PeerSyncTest, TestPluginEnable, MultiTermTest, LegacyHTMLStripCharFilterTest, ConvertedLegacyTest, TestDFRSimilarityFactory, UUIDFieldTest, TestQuerySenderListener, QueryEqualityTest, BasicFunctionalityTest, DistributedQueryElevationComponentTest, URLClassifyProcessorTest, TestArbitraryIndexDir, SimplePostToolTest, TestPhraseSuggestions, TestStressLucene, TestJmxIntegration, DirectSolrSpellCheckerTest, OverseerCollectionProcessorTest, OverseerTest, RecoveryZkTest, SpellCheckComponentTest, LeaderElectionIntegrationTest, LeaderElectionTest, DistributedSpellCheckComponentTest, ZkControllerTest, TestDistributedGrouping, TestDistributedSearch, SpellCheckCollatorTest, SoftAutoCommitTest, AutoCommitTest, BasicZkTest, TestFaceting, TestHashPartitioner, DistributedTermsComponentTest, StatsComponentTest, TestRecovery, SolrCoreTest, IndexBasedSpellCheckerTest, TestRangeQuery, DirectUpdateHandlerTest, SimpleFacetsTest, TestSort, TestFiltering, FileBasedSpellCheckerTest, SignatureUpdateProcessorFactoryTest, HighlighterTest, TestIndexSearcher, TestFunctionQuery, TestTrie, DirectSolrConnectionTest, CacheHeaderTest, PolyFieldTest, MoreLikeThisHandlerTest, DocumentBuilderTest, CurrencyFieldTest, DisMaxRequestHandlerTest, QueryParsingTest, TermsComponentTest, DistanceFunctionTest, FieldAnalysisRequestHandlerTest, PingRequestHandlerTest, TermVectorComponentTest, JsonLoaderTest, DocumentAnalysisRequestHandlerTest, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, TestValueSourceCache, DebugComponentTest, JSONWriterTest, ReturnFieldsTest, RequiredFieldsTest, TestOmitPositions, CopyFieldTest, TestQueryUtils, LoggingHandlerTest, SuggesterTSTTest, SolrCmdDistributorTest, UniqFieldsUpdateProcessorFactoryTest, BadIndexSchemaTest, SolrCoreCheckLockOnStartupTest, TestSolrDeletionPolicy1, TestLuceneMatchVersion, UpdateRequestProcessorFactoryTest, TestPropInject, NoCacheHeaderTest, PrimitiveFieldTypeTest, TestUpdate, TestBinaryField, HighlighterConfigTest, TestSolrDeletionPolicy2, TestMergePolicyConfig, TestDocSet, IndexReaderFactoryTest, TestSolrCoreProperties, EchoParamsTest, SpellPossibilityIteratorTest, TestPerFieldSimilarity, TestIBSimilarityFactory, TestCodecSupport, TimeZoneUtilsTest, DateMathParserTest, PluginInfoTest, OpenExchangeRatesOrgProviderTest, FileUtilsTest, TestBadConfig, DOMUtilTest, SystemInfoHandlerTest, ChaosMonkeyNothingIsSafeTest, PreAnalyzedFieldTest, ZkNodePropsTest, CircularListTest, AnalysisAfterCoreReloadTest, TestDocumentBuilder, PathHierarchyTokenizerFactoryTest, ClusterStateTest, CollectionsAPIDistributedZkTest, UnloadDistributedZkTest]
[junit4:junit4] Completed on J1 in 151.70s, 1 test, 1 failure <<< FAILURES!

[...truncated 10 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:381: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:361: 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:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1202: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:865: There were test failures: 254 suites, 1062 tests, 1 failure, 8 ignored (3 assumptions)

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



Mime
View raw message