You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/02/19 08:51:34 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.8.0-ea-b65) - Build #
4379 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/4379/
Java: 32bit/jdk1.8.0-ea-b65 -server -XX:+UseG1GC
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([45675EE2BB13B58B:C481D0FACC4CD5B7]: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 9499 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.UnloadDistributedZkTest
[junit4:junit4] 2> 0 T2323 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /k/l
[junit4:junit4] 2> 4 T2323 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220
[junit4:junit4] 2> 5 T2323 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 5 T2324 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 6 T2324 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4] 2> 6 T2324 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4] 2> 6 T2324 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4] 2> 6 T2324 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> 7 T2324 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4] 2> 106 T2323 oasc.ZkTestServer.run start zk server on port:35469
[junit4:junit4] 2> 106 T2323 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35469 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1a79432
[junit4:junit4] 2> 107 T2323 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 107 T2329 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:35469. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 107 T2329 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:35469, initiating session
[junit4:junit4] 2> 108 T2325 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:35107
[junit4:junit4] 2> 108 T2325 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:35107
[junit4:junit4] 2> 109 T2327 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4] 2> 750 T2327 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf16d75fe0000 with negotiated timeout 10000 for client /127.0.0.1:35107
[junit4:junit4] 2> 750 T2329 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:35469, sessionid = 0x13cf16d75fe0000, negotiated timeout = 10000
[junit4:junit4] 2> 750 T2330 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a79432 name:ZooKeeperConnection Watcher:127.0.0.1:35469 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 751 T2323 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 751 T2323 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 753 T2328 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf16d75fe0000
[junit4:junit4] 2> 753 T2330 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 753 T2325 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:35107 which had sessionid 0x13cf16d75fe0000
[junit4:junit4] 2> 753 T2323 oaz.ZooKeeper.close Session: 0x13cf16d75fe0000 closed
[junit4:junit4] 2> 754 T2323 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35469/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1f7abc0
[junit4:junit4] 2> 755 T2331 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:35469. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 755 T2323 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 755 T2325 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:35108
[junit4:junit4] 2> 755 T2331 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:35469, initiating session
[junit4:junit4] 2> 756 T2325 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:35108
[junit4:junit4] 2> 756 T2327 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf16d75fe0001 with negotiated timeout 10000 for client /127.0.0.1:35108
[junit4:junit4] 2> 756 T2331 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:35469, sessionid = 0x13cf16d75fe0001, negotiated timeout = 10000
[junit4:junit4] 2> 756 T2332 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f7abc0 name:ZooKeeperConnection Watcher:127.0.0.1:35469/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 757 T2323 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 757 T2323 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 759 T2323 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 760 T2323 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 762 T2323 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 763 T2323 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> 764 T2323 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 767 T2323 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> 767 T2323 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 770 T2323 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> 770 T2323 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 772 T2323 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> 772 T2323 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 774 T2323 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> 775 T2323 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 777 T2323 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> 777 T2323 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 779 T2323 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> 780 T2323 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 781 T2323 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> 782 T2323 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 784 T2323 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> 784 T2323 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 786 T2328 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf16d75fe0001
[junit4:junit4] 2> 787 T2332 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 787 T2325 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:35108 which had sessionid 0x13cf16d75fe0001
[junit4:junit4] 2> 787 T2323 oaz.ZooKeeper.close Session: 0x13cf16d75fe0001 closed
[junit4:junit4] 2> 860 T2323 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 869 T2323 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:33375
[junit4:junit4] 2> 870 T2323 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 870 T2323 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 871 T2323 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361260149003
[junit4:junit4] 2> 871 T2323 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361260149003/solr.xml
[junit4:junit4] 2> 872 T2323 oasc.CoreContainer.<init> New CoreContainer 18416714
[junit4:junit4] 2> 872 T2323 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361260149003/'
[junit4:junit4] 2> 873 T2323 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361260149003/'
[junit4:junit4] 2> 894 T2323 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 895 T2323 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 896 T2323 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 896 T2323 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 896 T2323 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 897 T2323 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 897 T2323 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 897 T2323 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 898 T2323 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 898 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 904 T2323 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 913 T2323 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:35469/solr
[junit4:junit4] 2> 914 T2323 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 914 T2323 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35469 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1bcff7c
[junit4:junit4] 2> 915 T2323 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 915 T2342 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:35469. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 916 T2342 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:35469, initiating session
[junit4:junit4] 2> 916 T2325 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:35110
[junit4:junit4] 2> 916 T2325 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:35110
[junit4:junit4] 2> 917 T2327 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf16d75fe0002 with negotiated timeout 20000 for client /127.0.0.1:35110
[junit4:junit4] 2> 917 T2342 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:35469, sessionid = 0x13cf16d75fe0002, negotiated timeout = 20000
[junit4:junit4] 2> 917 T2343 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bcff7c name:ZooKeeperConnection Watcher:127.0.0.1:35469 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 917 T2323 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 918 T2328 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf16d75fe0002
[junit4:junit4] 2> 918 T2343 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 918 T2325 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:35110 which had sessionid 0x13cf16d75fe0002
[junit4:junit4] 2> 918 T2323 oaz.ZooKeeper.close Session: 0x13cf16d75fe0002 closed
[junit4:junit4] 2> 919 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 921 T2323 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35469/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@af7234
[junit4:junit4] 2> 922 T2344 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:35469. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 922 T2323 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 922 T2344 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:35469, initiating session
[junit4:junit4] 2> 922 T2325 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:35111
[junit4:junit4] 2> 923 T2325 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:35111
[junit4:junit4] 2> 923 T2327 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf16d75fe0003 with negotiated timeout 20000 for client /127.0.0.1:35111
[junit4:junit4] 2> 923 T2344 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:35469, sessionid = 0x13cf16d75fe0003, negotiated timeout = 20000
[junit4:junit4] 2> 923 T2345 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@af7234 name:ZooKeeperConnection Watcher:127.0.0.1:35469/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 924 T2323 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 924 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 925 T2323 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 926 T2323 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33375_k%2Fl
[junit4:junit4] 2> 927 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:33375_k%2Fl Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:33375_k%2Fl
[junit4:junit4] 2> 927 T2323 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:33375_k%2Fl
[junit4:junit4] 2> 928 T2323 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 930 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0003 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> 931 T2323 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 932 T2323 oasc.Overseer.start Overseer (id=89211545073876995-127.0.0.1:33375_k%2Fl-n_0000000000) starting
[junit4:junit4] 2> 933 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 933 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 933 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 934 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 934 T2347 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 935 T2323 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 936 T2323 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 937 T2346 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 940 T2348 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361260149003/collection1
[junit4:junit4] 2> 940 T2348 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 941 T2348 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 941 T2348 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 941 T2348 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361260149003/collection1/'
[junit4:junit4] 2> 942 T2348 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361260149003/collection1/lib/README' to classloader
[junit4:junit4] 2> 942 T2348 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361260149003/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 963 T2348 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 992 T2348 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 993 T2348 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 996 T2348 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 1306 T2348 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1311 T2348 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1314 T2348 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1320 T2348 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1323 T2348 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1325 T2348 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1326 T2348 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1326 T2348 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361260149003/collection1/, dataDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/control/data/
[junit4:junit4] 2> 1327 T2348 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@a801a2
[junit4:junit4] 2> 1327 T2348 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1327 T2348 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/control/data forceNew:false
[junit4:junit4] 2> 1327 T2348 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/control/data
[junit4:junit4] 2> 1328 T2348 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/control/data/index/
[junit4:junit4] 2> 1328 T2348 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1328 T2348 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/control/data/index forceNew:false
[junit4:junit4] 2> 1329 T2348 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1aff53d lockFactory=org.apache.lucene.store.NativeFSLockFactory@6b4e88),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 1329 T2348 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 1330 T2348 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/control/data/index
[junit4:junit4] 2> 1330 T2348 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1331 T2348 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1331 T2348 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1331 T2348 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1332 T2348 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1332 T2348 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1332 T2348 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1332 T2348 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1332 T2348 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1334 T2348 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1336 T2348 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/control/data
[junit4:junit4] 2> 1337 T2348 oass.SolrIndexSearcher.<init> Opening Searcher@1294bff main
[junit4:junit4] 2> 1337 T2348 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/control/data/tlog
[junit4:junit4] 2> 1337 T2348 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1338 T2348 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1340 T2348 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/control/data
[junit4:junit4] 2> 1341 T2349 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1294bff main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1341 T2348 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1342 T2348 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1342 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0003 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> 2440 T2346 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2440 T2346 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:33375_k%2Fl",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:33375/k/l",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 2440 T2346 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 2441 T2346 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 2441 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0003 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> 2445 T2345 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> 3344 T2348 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 3344 T2348 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:33375/k/l collection:control_collection shard:shard1
[junit4:junit4] 2> 3345 T2348 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 3349 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0003 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> 3349 T2348 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 3350 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0003 type:create cxid:0x73 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3351 T2348 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 3351 T2348 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 3351 T2348 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:33375/k/l/collection1/
[junit4:junit4] 2> 3352 T2348 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 3352 T2348 oasc.SyncStrategy.syncToMe http://127.0.0.1:33375/k/l/collection1/ has no replicas
[junit4:junit4] 2> 3352 T2348 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:33375/k/l/collection1/
[junit4:junit4] 2> 3352 T2348 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 3355 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0003 type:create cxid:0x7d zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3947 T2346 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3951 T2345 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> 3957 T2348 oasc.ZkController.register We are http://127.0.0.1:33375/k/l/collection1/ and leader is http://127.0.0.1:33375/k/l/collection1/
[junit4:junit4] 2> 3957 T2348 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:33375/k/l
[junit4:junit4] 2> 3957 T2348 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 3958 T2348 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 3958 T2348 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 3959 T2348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3959 T2323 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 3960 T2323 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 3960 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 3964 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 3965 T2323 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35469/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1f66b75
[junit4:junit4] 2> 3969 T2350 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:35469. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3969 T2350 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:35469, initiating session
[junit4:junit4] 2> 3969 T2325 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:35117
[junit4:junit4] 2> 3970 T2325 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:35117
[junit4:junit4] 2> 3970 T2327 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf16d75fe0004 with negotiated timeout 10000 for client /127.0.0.1:35117
[junit4:junit4] 2> 3972 T2350 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:35469, sessionid = 0x13cf16d75fe0004, negotiated timeout = 10000
[junit4:junit4] 2> 3973 T2323 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3974 T2351 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f66b75 name:ZooKeeperConnection Watcher:127.0.0.1:35469/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3974 T2323 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3975 T2323 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 3976 T2323 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 4026 T2323 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 4028 T2323 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:45751
[junit4:junit4] 2> 4029 T2323 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 4029 T2323 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 4030 T2323 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361260152192
[junit4:junit4] 2> 4030 T2323 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361260152192/solr.xml
[junit4:junit4] 2> 4030 T2323 oasc.CoreContainer.<init> New CoreContainer 738773
[junit4:junit4] 2> 4031 T2323 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361260152192/'
[junit4:junit4] 2> 4031 T2323 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361260152192/'
[junit4:junit4] 2> 4046 T2323 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 4046 T2323 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 4047 T2323 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 4047 T2323 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 4047 T2323 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 4048 T2323 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 4048 T2323 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 4049 T2323 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 4049 T2323 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 4049 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 4055 T2323 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 4065 T2323 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:35469/solr
[junit4:junit4] 2> 4065 T2323 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 4066 T2323 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35469 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@15a0b93
[junit4:junit4] 2> 4066 T2323 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 4066 T2361 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:35469. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 4067 T2361 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:35469, initiating session
[junit4:junit4] 2> 4067 T2325 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:35120
[junit4:junit4] 2> 4067 T2325 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:35120
[junit4:junit4] 2> 4068 T2327 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf16d75fe0005 with negotiated timeout 20000 for client /127.0.0.1:35120
[junit4:junit4] 2> 4068 T2361 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:35469, sessionid = 0x13cf16d75fe0005, negotiated timeout = 20000
[junit4:junit4] 2> 4068 T2362 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15a0b93 name:ZooKeeperConnection Watcher:127.0.0.1:35469 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 4068 T2323 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 4069 T2328 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf16d75fe0005
[junit4:junit4] 2> 4070 T2325 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:35120 which had sessionid 0x13cf16d75fe0005
[junit4:junit4] 2> 4070 T2362 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 4070 T2323 oaz.ZooKeeper.close Session: 0x13cf16d75fe0005 closed
[junit4:junit4] 2> 4070 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 4073 T2323 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35469/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@5c5fbb
[junit4:junit4] 2> 4074 T2363 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:35469. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 4074 T2323 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 4074 T2363 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:35469, initiating session
[junit4:junit4] 2> 4074 T2325 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:35121
[junit4:junit4] 2> 4074 T2325 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:35121
[junit4:junit4] 2> 4075 T2327 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf16d75fe0006 with negotiated timeout 20000 for client /127.0.0.1:35121
[junit4:junit4] 2> 4075 T2363 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:35469, sessionid = 0x13cf16d75fe0006, negotiated timeout = 20000
[junit4:junit4] 2> 4075 T2364 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c5fbb name:ZooKeeperConnection Watcher:127.0.0.1:35469/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 4075 T2323 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 4076 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0006 type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 4076 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0006 type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 4077 T2323 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 5079 T2323 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45751_k%2Fl
[junit4:junit4] 2> 5079 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0006 type:delete cxid:0x9 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:45751_k%2Fl Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:45751_k%2Fl
[junit4:junit4] 2> 5081 T2323 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45751_k%2Fl
[junit4:junit4] 2> 5083 T2345 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 5083 T2351 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 5083 T2345 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> 5083 T2364 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 5087 T2365 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361260152192/collection1
[junit4:junit4] 2> 5087 T2365 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 5087 T2365 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 5087 T2365 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 5088 T2365 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361260152192/collection1/'
[junit4:junit4] 2> 5088 T2365 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361260152192/collection1/lib/README' to classloader
[junit4:junit4] 2> 5089 T2365 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361260152192/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 5111 T2365 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 5168 T2365 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 5168 T2365 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 5172 T2365 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 5454 T2346 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 5455 T2346 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:33375_k%2Fl",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:33375/k/l",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 5457 T2345 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> 5457 T2351 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> 5457 T2364 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> 5472 T2365 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 5477 T2365 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 5479 T2365 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 5487 T2365 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 5490 T2365 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 5493 T2365 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 5494 T2365 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 5495 T2365 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361260152192/collection1/, dataDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty1/
[junit4:junit4] 2> 5495 T2365 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@a801a2
[junit4:junit4] 2> 5496 T2365 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 5496 T2365 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty1 forceNew:false
[junit4:junit4] 2> 5496 T2365 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty1
[junit4:junit4] 2> 5497 T2365 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty1/index/
[junit4:junit4] 2> 5497 T2365 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 5497 T2365 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty1/index forceNew:false
[junit4:junit4] 2> 5499 T2365 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1790961 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a8efa0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 5499 T2365 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 5499 T2365 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty1/index
[junit4:junit4] 2> 5501 T2365 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 5501 T2365 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 5501 T2365 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 5502 T2365 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 5502 T2365 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 5503 T2365 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 5503 T2365 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 5503 T2365 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 5504 T2365 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 5507 T2365 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 5509 T2365 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty1
[junit4:junit4] 2> 5510 T2365 oass.SolrIndexSearcher.<init> Opening Searcher@15129e2 main
[junit4:junit4] 2> 5510 T2365 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty1/tlog
[junit4:junit4] 2> 5510 T2365 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 5510 T2365 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 5514 T2366 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@15129e2 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 5515 T2365 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 5515 T2365 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 6959 T2346 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 6960 T2346 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:45751_k%2Fl",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:45751/k/l",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 6960 T2346 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 6960 T2346 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 7046 T2351 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> 7046 T2345 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> 7046 T2364 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> 7516 T2365 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 7517 T2365 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:45751/k/l collection:collection1 shard:shard2
[junit4:junit4] 2> 7517 T2365 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 7521 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0006 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> 7521 T2365 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 7521 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0006 type:create cxid:0x47 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 7522 T2365 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 7522 T2365 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 7522 T2365 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:45751/k/l/collection1/
[junit4:junit4] 2> 7523 T2365 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 7523 T2365 oasc.SyncStrategy.syncToMe http://127.0.0.1:45751/k/l/collection1/ has no replicas
[junit4:junit4] 2> 7523 T2365 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:45751/k/l/collection1/
[junit4:junit4] 2> 7523 T2365 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 7525 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0006 type:create cxid:0x51 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8550 T2346 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8554 T2351 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> 8554 T2364 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> 8554 T2345 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> 8578 T2365 oasc.ZkController.register We are http://127.0.0.1:45751/k/l/collection1/ and leader is http://127.0.0.1:45751/k/l/collection1/
[junit4:junit4] 2> 8578 T2365 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:45751/k/l
[junit4:junit4] 2> 8578 T2365 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 8578 T2365 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 8578 T2365 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 8616 T2365 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8617 T2323 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 8617 T2323 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 8618 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 8671 T2323 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 8673 T2323 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47364
[junit4:junit4] 2> 8674 T2323 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 8674 T2323 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 8675 T2323 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361260156836
[junit4:junit4] 2> 8675 T2323 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361260156836/solr.xml
[junit4:junit4] 2> 8676 T2323 oasc.CoreContainer.<init> New CoreContainer 28994099
[junit4:junit4] 2> 8676 T2323 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361260156836/'
[junit4:junit4] 2> 8677 T2323 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361260156836/'
[junit4:junit4] 2> 8695 T2323 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 8695 T2323 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 8696 T2323 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 8696 T2323 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 8697 T2323 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 8697 T2323 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 8698 T2323 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 8698 T2323 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 8699 T2323 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 8699 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 8708 T2323 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 8717 T2323 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:35469/solr
[junit4:junit4] 2> 8718 T2323 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 8718 T2323 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35469 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@f5e2b3
[junit4:junit4] 2> 8719 T2376 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:35469. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 8719 T2323 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8719 T2376 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:35469, initiating session
[junit4:junit4] 2> 8719 T2325 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:35122
[junit4:junit4] 2> 8720 T2325 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:35122
[junit4:junit4] 2> 8721 T2327 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf16d75fe0007 with negotiated timeout 20000 for client /127.0.0.1:35122
[junit4:junit4] 2> 8721 T2376 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:35469, sessionid = 0x13cf16d75fe0007, negotiated timeout = 20000
[junit4:junit4] 2> 8722 T2377 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f5e2b3 name:ZooKeeperConnection Watcher:127.0.0.1:35469 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8722 T2323 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8723 T2328 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf16d75fe0007
[junit4:junit4] 2> 8723 T2377 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 8723 T2325 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:35122 which had sessionid 0x13cf16d75fe0007
[junit4:junit4] 2> 8723 T2323 oaz.ZooKeeper.close Session: 0x13cf16d75fe0007 closed
[junit4:junit4] 2> 8724 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 8726 T2323 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35469/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@16d039f
[junit4:junit4] 2> 8727 T2378 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:35469. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 8727 T2323 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8727 T2378 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:35469, initiating session
[junit4:junit4] 2> 8727 T2325 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:35123
[junit4:junit4] 2> 8728 T2325 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:35123
[junit4:junit4] 2> 8728 T2327 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf16d75fe0008 with negotiated timeout 20000 for client /127.0.0.1:35123
[junit4:junit4] 2> 8728 T2378 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:35469, sessionid = 0x13cf16d75fe0008, negotiated timeout = 20000
[junit4:junit4] 2> 8728 T2379 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16d039f name:ZooKeeperConnection Watcher:127.0.0.1:35469/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8729 T2323 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8729 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0008 type:create cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8730 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0008 type:create cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8732 T2323 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 9734 T2323 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47364_k%2Fl
[junit4:junit4] 2> 9735 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0008 type:delete cxid:0x9 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:47364_k%2Fl Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:47364_k%2Fl
[junit4:junit4] 2> 9735 T2323 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47364_k%2Fl
[junit4:junit4] 2> 9738 T2364 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> 9738 T2351 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9739 T2351 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> 9739 T2379 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9739 T2345 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9739 T2345 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> 9739 T2364 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9743 T2380 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361260156836/collection1
[junit4:junit4] 2> 9743 T2380 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 9744 T2380 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 9744 T2380 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 9745 T2380 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361260156836/collection1/'
[junit4:junit4] 2> 9745 T2380 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361260156836/collection1/lib/README' to classloader
[junit4:junit4] 2> 9746 T2380 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361260156836/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 9767 T2380 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 9798 T2380 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 9798 T2380 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 9802 T2380 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 10057 T2346 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 10058 T2346 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:45751_k%2Fl",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:45751/k/l",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 10060 T2364 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> 10060 T2345 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> 10060 T2351 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> 10060 T2379 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> 10201 T2380 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 10210 T2380 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 10214 T2380 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 10230 T2380 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 10234 T2380 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 10239 T2380 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 10240 T2380 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 10241 T2380 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361260156836/collection1/, dataDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty2/
[junit4:junit4] 2> 10242 T2380 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@a801a2
[junit4:junit4] 2> 10242 T2380 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 10243 T2380 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty2 forceNew:false
[junit4:junit4] 2> 10243 T2380 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty2
[junit4:junit4] 2> 10243 T2380 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty2/index/
[junit4:junit4] 2> 10244 T2380 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 10244 T2380 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty2/index forceNew:false
[junit4:junit4] 2> 10246 T2380 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8af97c lockFactory=org.apache.lucene.store.NativeFSLockFactory@c41a69),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 10246 T2380 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 10246 T2380 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty2/index
[junit4:junit4] 2> 10248 T2380 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 10248 T2380 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 10249 T2380 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 10249 T2380 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 10250 T2380 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 10250 T2380 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 10250 T2380 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 10251 T2380 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 10251 T2380 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 10255 T2380 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 10258 T2380 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty2
[junit4:junit4] 2> 10260 T2380 oass.SolrIndexSearcher.<init> Opening Searcher@1b33160 main
[junit4:junit4] 2> 10261 T2380 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty2/tlog
[junit4:junit4] 2> 10261 T2380 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 10262 T2380 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 10265 T2380 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty2
[junit4:junit4] 2> 10266 T2381 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b33160 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 10266 T2380 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 10267 T2380 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 11562 T2346 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 11563 T2346 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:47364_k%2Fl",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:47364/k/l",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 11563 T2346 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 11563 T2346 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 11566 T2345 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> 11566 T2351 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> 11566 T2379 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> 11566 T2364 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> 12268 T2380 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 12269 T2380 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:47364/k/l collection:collection1 shard:shard1
[junit4:junit4] 2> 12269 T2380 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 12273 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0008 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> 12274 T2380 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 12274 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0008 type:create cxid:0x46 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 12277 T2380 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 12277 T2380 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 12277 T2380 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:47364/k/l/collection1/
[junit4:junit4] 2> 12277 T2380 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 12278 T2380 oasc.SyncStrategy.syncToMe http://127.0.0.1:47364/k/l/collection1/ has no replicas
[junit4:junit4] 2> 12278 T2380 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:47364/k/l/collection1/
[junit4:junit4] 2> 12278 T2380 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 12280 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0008 type:create cxid:0x4f zxid:0x82 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13069 T2346 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13073 T2351 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> 13073 T2379 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> 13073 T2364 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> 13073 T2345 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> 13083 T2380 oasc.ZkController.register We are http://127.0.0.1:47364/k/l/collection1/ and leader is http://127.0.0.1:47364/k/l/collection1/
[junit4:junit4] 2> 13083 T2380 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:47364/k/l
[junit4:junit4] 2> 13083 T2380 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 13084 T2380 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 13084 T2380 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 13085 T2380 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13085 T2323 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 13086 T2323 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 13087 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 13153 T2323 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 13155 T2323 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36160
[junit4:junit4] 2> 13156 T2323 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 13156 T2323 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 13156 T2323 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361260161306
[junit4:junit4] 2> 13157 T2323 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361260161306/solr.xml
[junit4:junit4] 2> 13157 T2323 oasc.CoreContainer.<init> New CoreContainer 17043748
[junit4:junit4] 2> 13158 T2323 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361260161306/'
[junit4:junit4] 2> 13158 T2323 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361260161306/'
[junit4:junit4] 2> 13174 T2323 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 13175 T2323 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 13176 T2323 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 13176 T2323 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 13177 T2323 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 13177 T2323 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 13178 T2323 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 13178 T2323 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 13178 T2323 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 13179 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 13184 T2323 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 13194 T2323 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:35469/solr
[junit4:junit4] 2> 13194 T2323 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 13195 T2323 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35469 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1640d43
[junit4:junit4] 2> 13195 T2391 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:35469. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 13195 T2323 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 13196 T2391 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:35469, initiating session
[junit4:junit4] 2> 13196 T2325 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:35134
[junit4:junit4] 2> 13196 T2325 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:35134
[junit4:junit4] 2> 13197 T2327 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf16d75fe0009 with negotiated timeout 20000 for client /127.0.0.1:35134
[junit4:junit4] 2> 13197 T2391 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:35469, sessionid = 0x13cf16d75fe0009, negotiated timeout = 20000
[junit4:junit4] 2> 13197 T2392 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1640d43 name:ZooKeeperConnection Watcher:127.0.0.1:35469 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 13197 T2323 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 13198 T2328 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf16d75fe0009
[junit4:junit4] 2> 13198 T2392 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 13198 T2325 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:35134 which had sessionid 0x13cf16d75fe0009
[junit4:junit4] 2> 13198 T2323 oaz.ZooKeeper.close Session: 0x13cf16d75fe0009 closed
[junit4:junit4] 2> 13199 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 13201 T2323 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35469/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@fcd215
[junit4:junit4] 2> 13202 T2393 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:35469. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 13202 T2323 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 13203 T2393 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:35469, initiating session
[junit4:junit4] 2> 13203 T2325 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:35135
[junit4:junit4] 2> 13203 T2325 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:35135
[junit4:junit4] 2> 13204 T2327 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf16d75fe000a with negotiated timeout 20000 for client /127.0.0.1:35135
[junit4:junit4] 2> 13204 T2393 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:35469, sessionid = 0x13cf16d75fe000a, negotiated timeout = 20000
[junit4:junit4] 2> 13204 T2394 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fcd215 name:ZooKeeperConnection Watcher:127.0.0.1:35469/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 13204 T2323 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 13205 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe000a type:create cxid:0x1 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13205 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe000a type:create cxid:0x2 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13206 T2323 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 14208 T2323 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36160_k%2Fl
[junit4:junit4] 2> 14208 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe000a type:delete cxid:0x9 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:36160_k%2Fl Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:36160_k%2Fl
[junit4:junit4] 2> 14209 T2323 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36160_k%2Fl
[junit4:junit4] 2> 14211 T2364 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> 14211 T2351 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14211 T2394 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14211 T2351 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> 14212 T2345 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14212 T2345 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> 14212 T2379 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14212 T2379 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> 14213 T2364 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14217 T2395 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361260161306/collection1
[junit4:junit4] 2> 14217 T2395 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 14218 T2395 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 14218 T2395 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 14218 T2395 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361260161306/collection1/'
[junit4:junit4] 2> 14219 T2395 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361260161306/collection1/lib/README' to classloader
[junit4:junit4] 2> 14219 T2395 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361260161306/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 14241 T2395 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 14274 T2395 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 14275 T2395 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 14278 T2395 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 14576 T2346 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 14577 T2346 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:47364_k%2Fl",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:47364/k/l",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 14580 T2351 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> 14580 T2379 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> 14580 T2364 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> 14580 T2345 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> 14580 T2394 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> 14624 T2395 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 14630 T2395 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 14632 T2395 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 14640 T2395 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 14643 T2395 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 14645 T2395 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 14646 T2395 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 14647 T2395 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361260161306/collection1/, dataDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3/
[junit4:junit4] 2> 14647 T2395 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@a801a2
[junit4:junit4] 2> 14648 T2395 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 14648 T2395 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3 forceNew:false
[junit4:junit4] 2> 14649 T2395 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3
[junit4:junit4] 2> 14649 T2395 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3/index/
[junit4:junit4] 2> 14649 T2395 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 14649 T2395 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3/index forceNew:false
[junit4:junit4] 2> 14651 T2395 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1b3c6ca lockFactory=org.apache.lucene.store.NativeFSLockFactory@d55503),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 14651 T2395 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 14651 T2395 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3/index
[junit4:junit4] 2> 14653 T2395 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 14653 T2395 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 14654 T2395 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 14654 T2395 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 14655 T2395 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 14655 T2395 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 14655 T2395 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 14655 T2395 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 14656 T2395 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 14659 T2395 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 14661 T2395 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3
[junit4:junit4] 2> 14662 T2395 oass.SolrIndexSearcher.<init> Opening Searcher@fbf769 main
[junit4:junit4] 2> 14662 T2395 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3/tlog
[junit4:junit4] 2> 14663 T2395 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 14663 T2395 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 14666 T2396 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@fbf769 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 14666 T2395 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 14667 T2395 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 16084 T2346 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 16085 T2346 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:36160_k%2Fl",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36160/k/l",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 16085 T2346 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 16085 T2346 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 16276 T2379 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> 16276 T2394 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> 16276 T2364 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> 16276 T2351 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> 16277 T2345 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> 16668 T2395 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 16668 T2395 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36160/k/l collection:collection1 shard:shard2
[junit4:junit4] 2> 16670 T2395 oasc.ZkController.register We are http://127.0.0.1:36160/k/l/collection1/ and leader is http://127.0.0.1:45751/k/l/collection1/
[junit4:junit4] 2> 16670 T2395 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36160/k/l
[junit4:junit4] 2> 16671 T2395 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 16671 T2395 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C151 name=collection1 org.apache.solr.core.SolrCore@2667d6 url=http://127.0.0.1:36160/k/l/collection1 node=127.0.0.1:36160_k%2Fl C151_STATE=coll:collection1 core:collection1 props:{state=down, shard=null, roles=null, node_name=127.0.0.1:36160_k%2Fl, base_url=http://127.0.0.1:36160/k/l, collection=collection1, core=collection1}
[junit4:junit4] 2> 16671 T2397 C151 P36160 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 16672 T2395 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 16672 T2397 C151 P36160 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 16672 T2397 C151 P36160 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 16672 T2397 C151 P36160 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 16673 T2323 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 16673 T2323 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 16674 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 16677 T2397 C151 P36160 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 16748 T2323 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 16750 T2323 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50513
[junit4:junit4] 2> 16750 T2323 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 16751 T2323 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 16751 T2323 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361260164891
[junit4:junit4] 2> 16752 T2323 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361260164891/solr.xml
[junit4:junit4] 2> 16753 T2323 oasc.CoreContainer.<init> New CoreContainer 29079740
[junit4:junit4] 2> 16753 T2323 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361260164891/'
[junit4:junit4] 2> 16753 T2323 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361260164891/'
[junit4:junit4] 2> 16772 T2323 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 16772 T2323 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 16773 T2323 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 16773 T2323 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 16774 T2323 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 16774 T2323 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 16775 T2323 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 16775 T2323 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 16775 T2323 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 16776 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 16782 T2323 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 16791 T2323 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:35469/solr
[junit4:junit4] 2> 16792 T2323 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 16792 T2323 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35469 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@12baab9
[junit4:junit4] 2> 16793 T2407 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:35469. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 16793 T2323 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 16793 T2407 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:35469, initiating session
[junit4:junit4] 2> 16794 T2325 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:35150
[junit4:junit4] 2> 16794 T2325 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:35150
[junit4:junit4] 2> 16794 T2327 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf16d75fe000b with negotiated timeout 20000 for client /127.0.0.1:35150
[junit4:junit4] 2> 16794 T2407 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:35469, sessionid = 0x13cf16d75fe000b, negotiated timeout = 20000
[junit4:junit4] 2> 16795 T2408 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12baab9 name:ZooKeeperConnection Watcher:127.0.0.1:35469 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 16795 T2323 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 16796 T2328 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf16d75fe000b
[junit4:junit4] 2> 16796 T2325 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:35150 which had sessionid 0x13cf16d75fe000b
[junit4:junit4] 2> 16796 T2323 oaz.ZooKeeper.close Session: 0x13cf16d75fe000b closed
[junit4:junit4] 2> 16797 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 16799 T2323 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35469/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@b0ba29
[junit4:junit4] 2> 16800 T2408 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 16800 T2409 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:35469. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 16800 T2323 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 16801 T2325 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:35151
[junit4:junit4] 2> 16801 T2409 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:35469, initiating session
[junit4:junit4] 2> 16801 T2325 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:35151
[junit4:junit4] 2> 16802 T2327 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf16d75fe000c with negotiated timeout 20000 for client /127.0.0.1:35151
[junit4:junit4] 2> 16804 T2409 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:35469, sessionid = 0x13cf16d75fe000c, negotiated timeout = 20000
[junit4:junit4] 2> 16804 T2410 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b0ba29 name:ZooKeeperConnection Watcher:127.0.0.1:35469/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 16804 T2323 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 16805 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe000c type:create cxid:0x1 zxid:0xa2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 16806 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe000c type:create cxid:0x2 zxid:0xa3 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 16807 T2323 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 17781 T2346 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 17782 T2346 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:36160_k%2Fl",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36160/k/l",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 17816 T2345 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> 17817 T2394 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> 17817 T2410 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> 17816 T2379 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> 17817 T2364 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> 17817 T2351 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> 17817 T2323 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50513_k%2Fl
[junit4:junit4] 2> 17818 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe000c type:delete cxid:0xb zxid:0xa7 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:50513_k%2Fl Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:50513_k%2Fl
[junit4:junit4] 2> 17820 T2323 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50513_k%2Fl
[junit4:junit4] 2> 17825 T2410 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> 17825 T2364 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 17825 T2351 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 17825 T2345 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 17826 T2345 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> 17825 T2394 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> 17825 T2364 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> 17825 T2351 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> 17827 T2410 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 17827 T2379 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 17827 T2394 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 17828 T2379 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> 17831 T2411 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361260164891/collection1
[junit4:junit4] 2> 17831 T2411 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 17832 T2411 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 17832 T2411 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 17833 T2411 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361260164891/collection1/'
[junit4:junit4] 2> 17833 T2411 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361260164891/collection1/lib/README' to classloader
[junit4:junit4] 2> 17833 T2411 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361260164891/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 17862 T2411 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 17904 T2411 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 17905 T2411 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 17910 T2411 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 18237 T2411 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 18242 T2411 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 18244 T2411 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 18252 T2411 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 18254 T2411 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 18257 T2411 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 18258 T2411 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 18258 T2411 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361260164891/collection1/, dataDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4/
[junit4:junit4] 2> 18258 T2411 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@a801a2
[junit4:junit4] 2> 18259 T2411 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 18259 T2411 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4 forceNew:false
[junit4:junit4] 2> 18259 T2411 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4
[junit4:junit4] 2> 18260 T2411 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4/index/
[junit4:junit4] 2> 18260 T2411 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 18260 T2411 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4/index forceNew:false
[junit4:junit4] 2> 18261 T2411 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@823cae lockFactory=org.apache.lucene.store.NativeFSLockFactory@1f9a7ba),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 18261 T2411 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 18262 T2411 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4/index
[junit4:junit4] 2> 18262 T2411 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 18263 T2411 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 18263 T2411 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 18263 T2411 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 18264 T2411 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 18264 T2411 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 18264 T2411 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 18264 T2411 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 18265 T2411 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 18267 T2411 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 18269 T2411 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4
[junit4:junit4] 2> 18269 T2411 oass.SolrIndexSearcher.<init> Opening Searcher@1eeb53c main
[junit4:junit4] 2> 18269 T2411 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4/tlog
[junit4:junit4] 2> 18270 T2411 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 18270 T2411 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 18273 T2412 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1eeb53c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 18274 T2411 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 18274 T2411 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 19322 T2346 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 19322 T2346 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50513_k%2Fl",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50513/k/l",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 19323 T2346 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 19323 T2346 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 19326 T2410 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> 19326 T2394 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> 19326 T2364 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> 19326 T2351 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> 19326 T2345 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> 19326 T2379 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> 20278 T2411 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 20278 T2411 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50513/k/l collection:collection1 shard:shard1
[junit4:junit4] 2> 20280 T2411 oasc.ZkController.register We are http://127.0.0.1:50513/k/l/collection1/ and leader is http://127.0.0.1:47364/k/l/collection1/
[junit4:junit4] 2> 20280 T2411 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50513/k/l
[junit4:junit4] 2> 20281 T2411 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 20281 T2411 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C152 name=collection1 org.apache.solr.core.SolrCore@482367 url=http://127.0.0.1:50513/k/l/collection1 node=127.0.0.1:50513_k%2Fl C152_STATE=coll:collection1 core:collection1 props:{state=down, shard=null, roles=null, node_name=127.0.0.1:50513_k%2Fl, base_url=http://127.0.0.1:50513/k/l, collection=collection1, core=collection1}
[junit4:junit4] 2> 20281 T2413 C152 P50513 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 20282 T2411 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 20282 T2413 C152 P50513 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 20282 T2413 C152 P50513 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 20282 T2413 C152 P50513 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 20282 T2323 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 20283 T2413 C152 P50513 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 20283 T2323 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 20283 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 20286 T2323 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 20287 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 20290 T2359 oasc.CoreContainer.create Creating SolrCore 'unloadcollection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361260152192/unloadcollection1
[junit4:junit4] 2> 20290 T2359 oasc.ZkController.createCollectionZkNode Check for collection zkNode:unloadcollection
[junit4:junit4] 2> 20291 T2359 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:unloadcollection
[junit4:junit4] 2> 20291 T2359 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 20292 T2359 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 20292 T2359 oascc.SolrZkClient.makePath makePath: /collections/unloadcollection
[junit4:junit4] 2> 20293 T2359 oasc.ZkController.readConfigName Load collection config from:/collections/unloadcollection
[junit4:junit4] 2> 20294 T2359 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361260152192/unloadcollection1/'
[junit4:junit4] 2> 20344 T2359 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 20375 T2359 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 20376 T2359 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 20381 T2359 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> C151_STATE=coll:collection1 core:collection1 props:{state=recovering, shard=shard2, roles=null, node_name=127.0.0.1:36160_k%2Fl, base_url=http://127.0.0.1:36160/k/l, collection=collection1, core=collection1}
[junit4:junit4] 2> 20682 T2397 C151 P36160 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:45751/k/l/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 20682 T2397 C151 P36160 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:36160/k/l START replicas=[http://127.0.0.1:45751/k/l/collection1/] nUpdates=100
[junit4:junit4] 2> 20682 T2397 C151 P36160 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 20683 T2397 C151 P36160 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 20683 T2397 C151 P36160 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 20683 T2397 C151 P36160 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 20683 T2397 C151 P36160 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 20683 T2397 C151 P36160 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:45751/k/l/collection1/. core=collection1
[junit4:junit4] 2> 20683 T2397 C151 P36160 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C153 name=collection1 org.apache.solr.core.SolrCore@172d718 url=http://127.0.0.1:45751/k/l/collection1 node=127.0.0.1:45751_k%2Fl C153_STATE=coll:collection1 core:collection1 props:{state=active, shard=shard2, roles=null, node_name=127.0.0.1:45751_k%2Fl, base_url=http://127.0.0.1:45751/k/l, collection=collection1, core=collection1, leader=true}
[junit4:junit4] 2> 20687 T2360 C153 P45751 REQ /get {distrib=false&qt=/get&version=2&wt=javabin&getVersions=100} status=0 QTime=0
[junit4:junit4] 2> 20688 T2357 C153 P45751 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4] 2> 20688 T2357 C153 P45751 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty1
[junit4:junit4] 2> 20690 T2357 C153 P45751 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1790961 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a8efa0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 20690 T2357 C153 P45751 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 20691 T2357 C153 P45751 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1790961 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a8efa0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1790961 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a8efa0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 20692 T2357 C153 P45751 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 20692 T2357 C153 P45751 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty1
[junit4:junit4] 2> 20693 T2357 C153 P45751 oass.SolrIndexSearcher.<init> Opening Searcher@1d6b6be realtime
[junit4:junit4] 2> 20693 T2357 C153 P45751 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 20693 T2357 C153 P45751 /update {waitSearcher=true&openSearcher=false&commit=true&commit_end_point=true&version=2&wt=javabin&softCommit=false} {commit=} 0 5
[junit4:junit4] 2> 20694 T2397 C151 P36160 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 20694 T2397 C151 P36160 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 20697 T2360 C153 P45751 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 20698 T2360 C153 P45751 REQ /replication {command=indexversion&qt=/replication&version=2&wt=javabin} status=0 QTime=3
[junit4:junit4] 2> 20698 T2397 C151 P36160 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 20698 T2397 C151 P36160 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 20698 T2397 C151 P36160 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 20700 T2357 C153 P45751 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty1
[junit4:junit4] 2> 20700 T2357 C153 P45751 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty1/index
[junit4:junit4] 2> 20701 T2357 C153 P45751 REQ /replication {command=filelist&generation=2&qt=/replication&version=2&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 20701 T2397 C151 P36160 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 20702 T2397 C151 P36160 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3/index.20130219041928917 forceNew:false
[junit4:junit4] 2> 20702 T2397 C151 P36160 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3
[junit4:junit4] 2> 20702 T2397 C151 P36160 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@ae1234 lockFactory=org.apache.lucene.store.NativeFSLockFactory@15774d3) fullCopy=true
[junit4:junit4] 2> 20705 T2358 C153 P45751 REQ /replication {command=filecontent&file=segments_2&generation=2&qt=/replication&wt=filestream&checksum=true} status=0 QTime=0
[junit4:junit4] 2> 20707 T2359 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 20707 T2397 C151 P36160 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3/index
[junit4:junit4] 2> 20707 T2397 C151 P36160 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 20707 T2397 C151 P36160 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130219041928917
[junit4:junit4] 2> 20708 T2397 C151 P36160 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3
[junit4:junit4] 2> 20709 T2397 C151 P36160 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3
[junit4:junit4] 2> 20709 T2397 C151 P36160 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3/index/ new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3/index.20130219041928917
[junit4:junit4] 2> 20710 T2397 C151 P36160 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@ae1234 lockFactory=org.apache.lucene.store.NativeFSLockFactory@15774d3),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 20710 T2397 C151 P36160 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 20711 T2397 C151 P36160 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3
[junit4:junit4] 2> 20711 T2397 C151 P36160 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 20711 T2397 C151 P36160 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 20711 T2397 C151 P36160 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4] 2> 20712 T2397 C151 P36160 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3/index.20130219041928917
[junit4:junit4] 2> 20712 T2359 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 20712 T2397 C151 P36160 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3
[junit4:junit4] 2> 20713 T2397 C151 P36160 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@ae1234 lockFactory=org.apache.lucene.store.NativeFSLockFactory@15774d3),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 20713 T2397 C151 P36160 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 20713 T2397 C151 P36160 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 20714 T2397 C151 P36160 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3
[junit4:junit4] 2> 20714 T2397 C151 P36160 oass.SolrIndexSearcher.<init> Opening Searcher@35f3f4 main
[junit4:junit4] 2> 20714 T2396 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@35f3f4 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 20715 T2396 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3/index
[junit4:junit4] 2> 20715 T2359 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 20715 T2397 C151 P36160 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=false,expungeDeletes=false,softCommit=false}
[junit4:junit4] 2> 20715 T2397 C151 P36160 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@ae1234 lockFactory=org.apache.lucene.store.NativeFSLockFactory@15774d3),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@ae1234 lockFactory=org.apache.lucene.store.NativeFSLockFactory@15774d3),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4] 2> 20715 T2397 C151 P36160 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[segments_3]
[junit4:junit4] 2> 20716 T2397 C151 P36160 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3
[junit4:junit4] 2> 20716 T2397 C151 P36160 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 20716 T2397 C151 P36160 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3/index.20130219041928917
[junit4:junit4] 2> 20716 T2397 C151 P36160 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty3/index
[junit4:junit4] 2> 20716 T2397 C151 P36160 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 20716 T2397 C151 P36160 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 20716 T2397 C151 P36160 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 20716 T2397 C151 P36160 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 20717 T2397 C151 P36160 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 20722 T2359 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 20726 T2359 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 20728 T2359 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 20729 T2359 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 20731 T2359 oasc.SolrCore.<init> [unloadcollection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361260152192/unloadcollection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260168504unloadcollection1_1n/
[junit4:junit4] 2> 20731 T2359 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@a801a2
[junit4:junit4] 2> 20731 T2359 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 20732 T2359 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260168504unloadcollection1_1n forceNew:false
[junit4:junit4] 2> 20732 T2359 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260168504unloadcollection1_1n
[junit4:junit4] 2> 20733 T2359 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260168504unloadcollection1_1n/index/
[junit4:junit4] 2> 20733 T2359 oasc.SolrCore.initIndex WARNING [unloadcollection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260168504unloadcollection1_1n/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 20733 T2359 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260168504unloadcollection1_1n/index forceNew:false
[junit4:junit4] 2> 20734 T2359 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@52128f lockFactory=org.apache.lucene.store.NativeFSLockFactory@d5818f),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 20735 T2359 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 20735 T2359 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260168504unloadcollection1_1n/index
[junit4:junit4] 2> 20736 T2359 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 20736 T2359 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 20737 T2359 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 20737 T2359 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 20737 T2359 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 20738 T2359 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 20738 T2359 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 20738 T2359 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 20739 T2359 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 20741 T2359 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 20743 T2359 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260168504unloadcollection1_1n
[junit4:junit4] 2> 20744 T2359 oass.SolrIndexSearcher.<init> Opening Searcher@9cf10d main
[junit4:junit4] 2> 20744 T2359 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260168504unloadcollection1_1n/tlog
[junit4:junit4] 2> 20745 T2359 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 20745 T2359 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 20747 T2359 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260168504unloadcollection1_1n
[junit4:junit4] 2> 20748 T2416 oasc.SolrCore.registerSearcher [unloadcollection1] Registered new searcher Searcher@9cf10d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 20749 T2359 oasc.ZkController.publish publishing core=unloadcollection1 state=down
[junit4:junit4] 2> 20829 T2346 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 20830 T2346 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50513_k%2Fl",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50513/k/l",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 20831 T2346 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:36160_k%2Fl",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36160/k/l",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 20833 T2346 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:45751_k%2Fl",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:45751/k/l",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"unloadcollection",
[junit4:junit4] 2> "core":"unloadcollection1"}
[junit4:junit4] 2> 20833 T2346 oasc.Overseer$ClusterStateUpdater.createCollection Create collection unloadcollection with numShards 1
[junit4:junit4] 2> 20833 T2346 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 20836 T2351 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> 20836 T2379 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> 20836 T2364 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> 20837 T2345 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> 20836 T2394 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> 20836 T2410 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> 21750 T2359 oasc.CoreContainer.registerCore registering core: unloadcollection1
[junit4:junit4] 2> 21751 T2359 oasc.ZkController.register Register replica - core:unloadcollection1 address:http://127.0.0.1:45751/k/l collection:unloadcollection shard:shard1
[junit4:junit4] 2> 21751 T2359 oascc.SolrZkClient.makePath makePath: /collections/unloadcollection/leader_elect/shard1/election
[junit4:junit4] 2> 21755 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0006 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> 21756 T2359 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 21756 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0006 type:create cxid:0xa7 zxid:0xc4 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 21757 T2359 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 21758 T2359 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 21758 T2359 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:45751/k/l/unloadcollection1/
[junit4:junit4] 2> 21758 T2359 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 21758 T2359 oasc.SyncStrategy.syncToMe http://127.0.0.1:45751/k/l/unloadcollection1/ has no replicas
[junit4:junit4] 2> 21759 T2359 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:45751/k/l/unloadcollection1/
[junit4:junit4] 2> 21759 T2359 oascc.SolrZkClient.makePath makePath: /collections/unloadcollection/leaders/shard1
[junit4:junit4] 2> 21761 T2328 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf16d75fe0006 type:create cxid:0xb1 zxid:0xc8 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 22341 T2346 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 22345 T2351 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> 22345 T2364 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> 22345 T2394 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> 22345 T2379 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> 22345 T2345 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> 22345 T2410 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> 22363 T2359 oasc.ZkController.register We are http://127.0.0.1:45751/k/l/unloadcollection1/ and leader is http://127.0.0.1:45751/k/l/unloadcollection1/
[junit4:junit4] 2> 22364 T2359 oasc.ZkController.register No LogReplay needed for core=unloadcollection1 baseURL=http://127.0.0.1:45751/k/l
[junit4:junit4] 2> 22364 T2359 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 22364 T2359 oasc.ZkController.publish publishing core=unloadcollection1 state=active
[junit4:junit4] 2> 22365 T2359 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 22366 T2359 oasc.CoreContainer.persistFile Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361260152192/solr.xml
[junit4:junit4] 2> 22375 T2359 oasc.SolrXMLSerializer.persistFile Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361260152192/solr.xml
[junit4:junit4] 2> 22376 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 22378 T2323 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35469/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@19254fb
[junit4:junit4] 2> 22378 T2417 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:35469. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 22378 T2323 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 22379 T2417 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:35469, initiating session
[junit4:junit4] 2> 22379 T2325 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:35160
[junit4:junit4] 2> 22379 T2325 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:35160
[junit4:junit4] 2> 22380 T2327 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf16d75fe000d with negotiated timeout 10000 for client /127.0.0.1:35160
[junit4:junit4] 2> 22380 T2417 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:35469, sessionid = 0x13cf16d75fe000d, negotiated timeout = 10000
[junit4:junit4] 2> 22382 T2418 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19254fb name:ZooKeeperConnection Watcher:127.0.0.1:35469/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 22383 T2323 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 22386 T2323 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 22388 T2323 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 22389 T2323 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 22393 T2375 oasc.CoreContainer.create Creating SolrCore 'unloadcollection2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361260156836/unloadcollection2
[junit4:junit4] 2> 22394 T2375 oasc.ZkController.createCollectionZkNode Check for collection zkNode:unloadcollection
[junit4:junit4] 2> 22394 T2375 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 22395 T2375 oasc.ZkController.readConfigName Load collection config from:/collections/unloadcollection
[junit4:junit4] 2> 22396 T2375 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361260156836/unloadcollection2/'
[junit4:junit4] 2> 22426 T2375 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 22491 T2375 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 22492 T2375 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 22495 T2375 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 22847 T2375 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 22852 T2375 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 22854 T2375 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 22861 T2375 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 22864 T2375 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 22866 T2375 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 22867 T2375 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 22867 T2375 oasc.SolrCore.<init> [unloadcollection2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361260156836/unloadcollection2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260170608unloadcollection1_2n/
[junit4:junit4] 2> 22868 T2375 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@a801a2
[junit4:junit4] 2> 22869 T2375 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 22869 T2375 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260170608unloadcollection1_2n forceNew:false
[junit4:junit4] 2> 22870 T2375 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260170608unloadcollection1_2n
[junit4:junit4] 2> 22870 T2375 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260170608unloadcollection1_2n/index/
[junit4:junit4] 2> 22870 T2375 oasc.SolrCore.initIndex WARNING [unloadcollection2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260170608unloadcollection1_2n/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 22871 T2375 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260170608unloadcollection1_2n/index forceNew:false
[junit4:junit4] 2> 22872 T2375 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@d4fee0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b97c96),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 22872 T2375 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 22872 T2375 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260170608unloadcollection1_2n/index
[junit4:junit4] 2> 22874 T2375 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 22874 T2375 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 22874 T2375 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 22875 T2375 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 22875 T2375 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 22875 T2375 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 22876 T2375 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 22876 T2375 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 22876 T2375 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 22879 T2375 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 22881 T2375 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260170608unloadcollection1_2n
[junit4:junit4] 2> 22881 T2375 oass.SolrIndexSearcher.<init> Opening Searcher@1b017e8 main
[junit4:junit4] 2> 22882 T2375 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260170608unloadcollection1_2n/tlog
[junit4:junit4] 2> 22882 T2375 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 22882 T2375 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 22884 T2375 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1361260148220/1361260170608unloadcollection1_2n
[junit4:junit4] 2> 22885 T2419 oasc.SolrCore.registerSearcher [unloadcollection2] Registered new searcher Searcher@1b017e8 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 22885 T2375 oasc.ZkController.publish publishing core=unloadcollection2 state=down
[junit4:junit4] 2> 22886 T2375 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> C152_STATE=coll:collection1 core:collection1 props:{state=recovering, shard=shard1, roles=null, node_name=127.0.0.1:50513_k%2Fl, base_url=http://127.0.0.1:50513/k/l, collection=collection1, core=collection1}
[junit4:junit4] 2> 23287 T2413 C152 P50513 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:47364/k/l/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 23287 T2413 C152 P50513 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:50513/k/l START replicas=[http://127.0.0.1:47364/k/l/collection1/] nUpdates=100
[junit4:junit4] 2> 23287 T2413 C152 P50513 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 23287 T2413 C152 P50513 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 23287 T2413 C152 P50513 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 23288 T2413 C152 P50513 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 23288 T2413 C152 P50513 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 23288 T2413 C152 P50513 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:47364/k/l/collection1/. core=collection1
[junit4:junit4] 2> 23288 T2413 C152 P50513 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C154 name=collection1 org.apache.solr.core.SolrCore@415f88 url=http://127.0.0.1:47364/k/l/collection1 node=127.0.0.1:47364_k%2Fl C154_STATE=coll:collection1 core:collection1 props:{state=active, shard=shard1, roles=null, node_name=127.0.0.1:47364_k%2Fl, base_url=http://127.0.0.1:47364/k/l, collection=collection1, core=collection1, leader=true}
[junit4:junit4] 2> 23292 T2370 C154 P47364 REQ /get {distrib=false&qt=/get&version=2&wt=javabin&getVersions=100} status=0 QTime=0
[junit4:junit4] 2> 23294 T2374 C154 P47364 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4] 2> 23294 T2374 C154 P47364 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty2
[junit4:junit4] 2> 23295 T2374 C154 P47364 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8af97c lockFactory=org.apache.lucene.store.NativeFSLockFactory@c41a69),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 23295 T2374 C154 P47364 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 23296 T2374 C154 P47364 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8af97c lockFactory=org.apache.lucene.store.NativeFSLockFactory@c41a69),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8af97c lockFactory=org.apache.lucene.store.NativeFSLockFactory@c41a69),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 23296 T2374 C154 P47364 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 23296 T2374 C154 P47364 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty2
[junit4:junit4] 2> 23297 T2374 C154 P47364 oass.SolrIndexSearcher.<init> Opening Searcher@192c30d realtime
[junit4:junit4] 2> 23297 T2374 C154 P47364 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 23297 T2374 C154 P47364 /update {waitSearcher=true&openSearcher=false&commit=true&commit_end_point=true&version=2&wt=javabin&softCommit=false} {commit=} 0 3
[junit4:junit4] 2> 23298 T2413 C152 P50513 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 23298 T2413 C152 P50513 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 23299 T2370 C154 P47364 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 23299 T2370 C154 P47364 REQ /replication {command=indexversion&qt=/replication&version=2&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 23300 T2413 C152 P50513 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 23300 T2413 C152 P50513 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 23300 T2413 C152 P50513 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 23301 T2374 C154 P47364 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty2
[junit4:junit4] 2> 23302 T2374 C154 P47364 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty2/index
[junit4:junit4] 2> 23302 T2374 C154 P47364 REQ /replication {command=filelist&generation=2&qt=/replication&version=2&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 23302 T2413 C152 P50513 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 23303 T2413 C152 P50513 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4/index.20130219041931517 forceNew:false
[junit4:junit4] 2> 23303 T2413 C152 P50513 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4
[junit4:junit4] 2> 23303 T2413 C152 P50513 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@10a762d lockFactory=org.apache.lucene.store.NativeFSLockFactory@a37186) fullCopy=true
[junit4:junit4] 2> 23306 T2373 C154 P47364 REQ /replication {command=filecontent&file=segments_2&generation=2&qt=/replication&wt=filestream&checksum=true} status=0 QTime=0
[junit4:junit4] 2> 23307 T2413 C152 P50513 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4/index
[junit4:junit4] 2> 23307 T2413 C152 P50513 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 23307 T2413 C152 P50513 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130219041931517
[junit4:junit4] 2> 23308 T2413 C152 P50513 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4
[junit4:junit4] 2> 23308 T2413 C152 P50513 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4
[junit4:junit4] 2> 23308 T2413 C152 P50513 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4/index/ new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4/index.20130219041931517
[junit4:junit4] 2> 23309 T2413 C152 P50513 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@10a762d lockFactory=org.apache.lucene.store.NativeFSLockFactory@a37186),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 23309 T2413 C152 P50513 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 23309 T2413 C152 P50513 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4
[junit4:junit4] 2> 23310 T2413 C152 P50513 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 23310 T2413 C152 P50513 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 23310 T2413 C152 P50513 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4] 2> 23310 T2413 C152 P50513 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4/index.20130219041931517
[junit4:junit4] 2> 23310 T2413 C152 P50513 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4
[junit4:junit4] 2> 23311 T2413 C152 P50513 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@10a762d lockFactory=org.apache.lucene.store.NativeFSLockFactory@a37186),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 23311 T2413 C152 P50513 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 23311 T2413 C152 P50513 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 23311 T2413 C152 P50513 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4
[junit4:junit4] 2> 23311 T2413 C152 P50513 oass.SolrIndexSearcher.<init> Opening Searcher@4dc939 main
[junit4:junit4] 2> 23314 T2412 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4dc939 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 23314 T2412 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4/index
[junit4:junit4] 2> 23314 T2413 C152 P50513 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=false,expungeDeletes=false,softCommit=false}
[junit4:junit4] 2> 23315 T2413 C152 P50513 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@10a762d lockFactory=org.apache.lucene.store.NativeFSLockFactory@a37186),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@10a762d lockFactory=org.apache.lucene.store.NativeFSLockFactory@a37186),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4] 2> 23315 T2413 C152 P50513 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[segments_3]
[junit4:junit4] 2> 23315 T2413 C152 P50513 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4
[junit4:junit4] 2> 23315 T2413 C152 P50513 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 23315 T2413 C152 P50513 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4/index.20130219041931517
[junit4:junit4] 2> 23315 T2413 C152 P50513 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-1361260148219/jetty4/index
[junit4:junit4] 2> 23316 T2413 C152 P50513 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 23316 T2413 C152 P50513 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 23316 T2413 C152 P50513 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 23316 T2413 C152 P50513 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 23317 T2413 C152 P50513 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 23849 T2346 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 23850 T2346 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:45751_k%2Fl",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:45751/k/l",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"unloadcollection",
[junit4:junit4] 2> "core":"unloadcollection1"}
[junit4:junit4] 2> 23853 T2346 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:47364_k%2Fl",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:47364/k/l",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"unloadcollection",
[junit4:junit4] 2> "core":"unloadcollection2"}
[junit4:junit4] 2> 23854 T2346 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4] 2> 23854 T2346 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 23855 T2346 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50513_k%2Fl",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50513/k/l",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 23857 T2345 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> 23857 T2394 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> 23858 T2418 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> 23857 T2351 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> 23857 T2379 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> 23858 T2364 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> 23858 T2410 oascc.ZkStateR
[...truncated too long message...]
it4: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> 141578 T2323 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 141588 T2322 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4:junit4] 2> 141785 T2326 oazs.SessionTrackerImpl.run SessionTrackerImpl exited loop!
[junit4:junit4] 2> 142675 T2410 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 142675 T2410 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> 142675 T2410 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 142675 T2410 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {text=MockVariableIntBlock(baseBlockSize=60), a_si=PostingsFormat(name=Memory doPackFST= true), multiDefault=PostingsFormat(name=Memory doPackFST= true), range_facet_l=Pulsing41(freqCutoff=8 minBlockSize=72 maxBlockSize=161), id=PostingsFormat(name=TestBloomFilteredLucene41Postings), timestamp=Pulsing41(freqCutoff=8 minBlockSize=72 maxBlockSize=161), range_facet_sl=MockVariableIntBlock(baseBlockSize=60), _version_=Pulsing41(freqCutoff=8 minBlockSize=72 maxBlockSize=161), other_tl1=Pulsing41(freqCutoff=8 minBlockSize=72 maxBlockSize=161), intDefault=Pulsing41(freqCutoff=8 minBlockSize=72 maxBlockSize=161), range_facet_si=PostingsFormat(name=Memory doPackFST= true), a_t=Pulsing41(freqCutoff=8 minBlockSize=72 maxBlockSize=161)}, docValues:{timestamp=DocValuesFormat(name=CheapBastard)}, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=bg_BG, timezone=Canada/Newfoundland
[junit4:junit4] 2> NOTE: Linux 3.2.0-37-generic i386/Oracle Corporation 1.8.0-ea (32-bit)/cpus=8,threads=1,free=135142320,total=452984832
[junit4:junit4] 2> NOTE: All tests run in this JVM: [HighlighterConfigTest, SampleTest, ShardRoutingTest, ExternalFileFieldSortTest, TestStressVersions, ResourceLoaderTest, TestLFUCache, TestXIncludeConfig, NoCacheHeaderTest, TestGroupingSearch, DateMathParserTest, SyncSliceTest, SpellCheckComponentTest, CoreAdminHandlerTest, TestNumberUtils, SolrCmdDistributorTest, SimpleFacetsTest, SchemaVersionSpecificBehaviorTest, SOLR749Test, ZkCLITest, ChaosMonkeySafeLeaderTest, DirectUpdateHandlerOptimizeTest, DirectSolrConnectionTest, CSVRequestHandlerTest, SliceStateUpdateTest, TestLMJelinekMercerSimilarityFactory, LeaderElectionIntegrationTest, PreAnalyzedFieldTest, TestFaceting, TestIndexSearcher, UpdateRequestProcessorFactoryTest, TestSuggestSpellingConverter, RegexBoostProcessorTest, DateFieldTest, TestDefaultSimilarityFactory, ResponseLogComponentTest, SpatialFilterTest, TestFastLRUCache, SolrRequestParserTest, TestPseudoReturnFields, RequestHandlersTest, DefaultValueUpdateProcessorTest, TestFiltering, TestIBSimilarityFactory, ClusterStateTest, TestSolrQueryParser, MoreLikeThisHandlerTest, ZkControllerTest, StatelessScriptUpdateProcessorFactoryTest, SynonymTokenizerTest, TestDocumentBuilder, TestWordDelimiterFilterFactory, TestCoreContainer, FieldAnalysisRequestHandlerTest, TestIndexingPerformance, TermsComponentTest, CircularListTest, SuggesterWFSTTest, TestCollationField, NotRequiredUniqueKeyTest, FastVectorHighlighterTest, TestDistributedSearch, SoftAutoCommitTest, BasicZkTest, DistributedTermsComponentTest, IndexBasedSpellCheckerTest, TestRangeQuery, DirectSolrSpellCheckerTest, FileBasedSpellCheckerTest, QueryElevationComponentTest, SortByFunctionTest, SignatureUpdateProcessorFactoryTest, TestBinaryResponseWriter, TestJmxIntegration, HighlighterTest, TestFunctionQuery, CacheHeaderTest, TestCSVLoader, PolyFieldTest, DocumentBuilderTest, MBeansHandlerTest, DistributedQueryElevationComponentTest, CurrencyFieldTest, DisMaxRequestHandlerTest, BinaryUpdateRequestHandlerTest, QueryParsingTest, DistanceFunctionTest, XsltUpdateRequestHandlerTest, MinimalSchemaTest, StandardRequestHandlerTest, TestQueryTypes, TestPHPSerializedResponseWriter, XmlUpdateRequestHandlerTest, PingRequestHandlerTest, JsonLoaderTest, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, TestReversedWildcardFilterFactory, JSONWriterTest, SearchHandlerTest, TestOmitPositions, SuggesterFSTTest, CopyFieldTest, TestArbitraryIndexDir, TestQueryUtils, LoggingHandlerTest, UniqFieldsUpdateProcessorFactoryTest, SuggesterTest, ShowFileRequestHandlerTest, TestSearchPerf, SolrCoreCheckLockOnStartupTest, TestLuceneMatchVersion, TestWriterPerf, AlternateDirectoryTest, BadComponentTest, TestUpdate, TestMergePolicyConfig, TestDocSet, TestQuerySenderNoQuery, IndexReaderFactoryTest, NumericFieldsTest, OutputWriterTest, MultiTermTest, TestSolrCoreProperties, TestJmxMonitoredMap, TestConfig, EchoParamsTest, SpellPossibilityIteratorTest, TestBM25SimilarityFactory, TestPhraseSuggestions, TestLMDirichletSimilarityFactory, TestPerFieldSimilarity, TestPluginEnable, TestDFRSimilarityFactory, TestCodecSupport, URLClassifyProcessorTest, PluginInfoTest, PrimUtilsTest, FileUtilsTest, TestSystemIdResolver, TestSolrXMLSerializer, SpellingQueryConverterTest, TestBadConfig, RAMDirectoryFactoryTest, SystemInfoHandlerTest, TestUtils, ChaosMonkeyNothingIsSafeTest, AnalysisAfterCoreReloadTest, BasicDistributedZk2Test, UnloadDistributedZkTest]
[junit4:junit4] Completed on J0 in 142.86s, 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, 1052 tests, 1 failure, 8 ignored (3 assumptions)
Total time: 38 minutes 49 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:+UseG1GC
Email was triggered for: Failure
Sending email for trigger: Failure