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 09:28:10 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.8.0-ea-b65) - Build #
4354 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/4354/
Java: 32bit/jdk1.8.0-ea-b65 -server -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.UnloadDistributedZkTest.testDistribSearch
Error Message:
Still found shard
Stack Trace:
java.lang.AssertionError: Still found shard
at __randomizedtesting.SeedInfo.seed([54479517CD65882E:D5A11B0FBA3AE812]: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 9372 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.UnloadDistributedZkTest
[junit4:junit4] 2> 1 T3036 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /ws_whv/
[junit4:junit4] 2> 3 T3036 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138
[junit4:junit4] 2> 4 T3036 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 4 T3037 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 5 T3037 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4] 2> 5 T3037 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4] 2> 5 T3037 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4] 2> 5 T3037 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> 6 T3037 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4] 2> 104 T3036 oasc.ZkTestServer.run start zk server on port:39739
[junit4:junit4] 2> 105 T3036 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39739 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@889a8c
[junit4:junit4] 2> 106 T3036 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 106 T3042 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:39739. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 106 T3042 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:39739, initiating session
[junit4:junit4] 2> 106 T3038 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51236
[junit4:junit4] 2> 106 T3038 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51236
[junit4:junit4] 2> 107 T3040 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4] 2> 117 T3040 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf18f0b540000 with negotiated timeout 10000 for client /127.0.0.1:51236
[junit4:junit4] 2> 117 T3042 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:39739, sessionid = 0x13cf18f0b540000, negotiated timeout = 10000
[junit4:junit4] 2> 118 T3043 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@889a8c name:ZooKeeperConnection Watcher:127.0.0.1:39739 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 118 T3036 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 118 T3036 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 120 T3041 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf18f0b540000
[junit4:junit4] 2> 120 T3043 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 121 T3038 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:51236 which had sessionid 0x13cf18f0b540000
[junit4:junit4] 2> 120 T3036 oaz.ZooKeeper.close Session: 0x13cf18f0b540000 closed
[junit4:junit4] 2> 121 T3036 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39739/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@9209a5
[junit4:junit4] 2> 122 T3036 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 122 T3044 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:39739. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 122 T3044 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:39739, initiating session
[junit4:junit4] 2> 122 T3038 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51237
[junit4:junit4] 2> 122 T3038 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51237
[junit4:junit4] 2> 123 T3044 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:39739, sessionid = 0x13cf18f0b540001, negotiated timeout = 10000
[junit4:junit4] 2> 123 T3040 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf18f0b540001 with negotiated timeout 10000 for client /127.0.0.1:51237
[junit4:junit4] 2> 123 T3045 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9209a5 name:ZooKeeperConnection Watcher:127.0.0.1:39739/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 123 T3036 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 124 T3036 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 126 T3036 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 127 T3036 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 128 T3036 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 136 T3036 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 137 T3036 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 145 T3036 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 146 T3036 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 149 T3036 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 150 T3036 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 152 T3036 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 152 T3036 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 154 T3036 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 155 T3036 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 157 T3036 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 158 T3036 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 160 T3036 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 160 T3036 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 162 T3036 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 163 T3036 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 169 T3036 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 170 T3036 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 172 T3041 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf18f0b540001
[junit4:junit4] 2> 172 T3038 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:51237 which had sessionid 0x13cf18f0b540001
[junit4:junit4] 2> 172 T3045 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 172 T3036 oaz.ZooKeeper.close Session: 0x13cf18f0b540001 closed
[junit4:junit4] 2> 252 T3036 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 258 T3036 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:32984
[junit4:junit4] 2> 258 T3036 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 259 T3036 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 259 T3036 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361262349307
[junit4:junit4] 2> 260 T3036 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361262349307/solr.xml
[junit4:junit4] 2> 260 T3036 oasc.CoreContainer.<init> New CoreContainer 21333879
[junit4:junit4] 2> 261 T3036 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361262349307/'
[junit4:junit4] 2> 262 T3036 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361262349307/'
[junit4:junit4] 2> 285 T3036 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 285 T3036 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 286 T3036 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 286 T3036 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 287 T3036 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 287 T3036 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 288 T3036 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 288 T3036 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 289 T3036 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 289 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 298 T3036 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 308 T3036 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:39739/solr
[junit4:junit4] 2> 309 T3036 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 309 T3036 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39739 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@319977
[junit4:junit4] 2> 310 T3055 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:39739. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 310 T3036 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 310 T3055 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:39739, initiating session
[junit4:junit4] 2> 311 T3038 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51238
[junit4:junit4] 2> 311 T3038 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51238
[junit4:junit4] 2> 312 T3040 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf18f0b540002 with negotiated timeout 20000 for client /127.0.0.1:51238
[junit4:junit4] 2> 312 T3055 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:39739, sessionid = 0x13cf18f0b540002, negotiated timeout = 20000
[junit4:junit4] 2> 312 T3056 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@319977 name:ZooKeeperConnection Watcher:127.0.0.1:39739 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 313 T3036 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 313 T3041 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf18f0b540002
[junit4:junit4] 2> 314 T3038 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:51238 which had sessionid 0x13cf18f0b540002
[junit4:junit4] 2> 314 T3056 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 314 T3036 oaz.ZooKeeper.close Session: 0x13cf18f0b540002 closed
[junit4:junit4] 2> 314 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 317 T3036 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39739/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@62af74
[junit4:junit4] 2> 317 T3057 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:39739. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 317 T3036 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 318 T3057 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:39739, initiating session
[junit4:junit4] 2> 318 T3038 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51239
[junit4:junit4] 2> 318 T3038 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51239
[junit4:junit4] 2> 319 T3040 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf18f0b540003 with negotiated timeout 20000 for client /127.0.0.1:51239
[junit4:junit4] 2> 319 T3057 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:39739, sessionid = 0x13cf18f0b540003, negotiated timeout = 20000
[junit4:junit4] 2> 319 T3058 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@62af74 name:ZooKeeperConnection Watcher:127.0.0.1:39739/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 319 T3036 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 320 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 321 T3036 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 322 T3036 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32984_ws_whv
[junit4:junit4] 2> 323 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:32984_ws_whv Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:32984_ws_whv
[junit4:junit4] 2> 323 T3036 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:32984_ws_whv
[junit4:junit4] 2> 325 T3036 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 327 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540003 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> 327 T3036 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 328 T3036 oasc.Overseer.start Overseer (id=89211689313239043-127.0.0.1:32984_ws_whv-n_0000000000) starting
[junit4:junit4] 2> 329 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 329 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 330 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 330 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 331 T3060 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 331 T3036 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 332 T3036 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 333 T3059 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 335 T3061 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361262349307/collection1
[junit4:junit4] 2> 335 T3061 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 336 T3061 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 336 T3061 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 337 T3061 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361262349307/collection1/'
[junit4:junit4] 2> 337 T3061 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361262349307/collection1/lib/README' to classloader
[junit4:junit4] 2> 337 T3061 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361262349307/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 363 T3061 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 392 T3061 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 393 T3061 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 396 T3061 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 672 T3061 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 676 T3061 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 679 T3061 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 685 T3061 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 687 T3061 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 689 T3061 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 690 T3061 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 691 T3061 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1361262349307/collection1/, dataDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/control/data/
[junit4:junit4] 2> 691 T3061 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@857f67
[junit4:junit4] 2> 691 T3061 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 692 T3061 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/control/data forceNew:false
[junit4:junit4] 2> 692 T3061 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/control/data
[junit4:junit4] 2> 692 T3061 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/control/data/index/
[junit4:junit4] 2> 693 T3061 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 693 T3061 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/control/data/index forceNew:false
[junit4:junit4] 2> 694 T3061 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@182bae5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@68057d),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 694 T3061 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 694 T3061 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/control/data/index
[junit4:junit4] 2> 695 T3061 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 695 T3061 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 696 T3061 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 696 T3061 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 696 T3061 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 696 T3061 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 696 T3061 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 697 T3061 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 697 T3061 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 699 T3061 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 701 T3061 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/control/data
[junit4:junit4] 2> 701 T3061 oass.SolrIndexSearcher.<init> Opening Searcher@9931de main
[junit4:junit4] 2> 701 T3061 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/control/data/tlog
[junit4:junit4] 2> 702 T3061 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 702 T3061 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 703 T3061 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/control/data
[junit4:junit4] 2> 704 T3062 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9931de main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 704 T3061 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 704 T3061 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 704 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540003 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> 1835 T3059 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1835 T3059 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "node_name":"127.0.0.1:32984_ws_whv",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:32984/ws_whv",
[junit4:junit4] 2> "shard":null}
[junit4:junit4] 2> 1835 T3059 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 1835 T3059 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 1836 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540003 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> 1838 T3058 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> 2715 T3061 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2715 T3061 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:32984/ws_whv collection:control_collection shard:shard1
[junit4:junit4] 2> 2715 T3061 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2720 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540003 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> 2720 T3061 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2720 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540003 type:create cxid:0x73 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 2721 T3061 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2721 T3061 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2721 T3061 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:32984/ws_whv/collection1/
[junit4:junit4] 2> 2722 T3061 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2722 T3061 oasc.SyncStrategy.syncToMe http://127.0.0.1:32984/ws_whv/collection1/ has no replicas
[junit4:junit4] 2> 2722 T3061 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:32984/ws_whv/collection1/
[junit4:junit4] 2> 2722 T3061 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 2724 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540003 type:create cxid:0x7d zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3341 T3059 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3346 T3058 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> 3376 T3061 oasc.ZkController.register We are http://127.0.0.1:32984/ws_whv/collection1/ and leader is http://127.0.0.1:32984/ws_whv/collection1/
[junit4:junit4] 2> 3377 T3061 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:32984/ws_whv
[junit4:junit4] 2> 3377 T3061 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 3377 T3061 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 3377 T3061 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 3378 T3061 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3379 T3036 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 3379 T3036 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 3380 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 3382 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 3383 T3036 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39739/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@e2923
[junit4:junit4] 2> 3384 T3036 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3384 T3063 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:39739. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3384 T3063 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:39739, initiating session
[junit4:junit4] 2> 3384 T3038 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51242
[junit4:junit4] 2> 3384 T3038 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51242
[junit4:junit4] 2> 3385 T3040 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf18f0b540004 with negotiated timeout 10000 for client /127.0.0.1:51242
[junit4:junit4] 2> 3385 T3063 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:39739, sessionid = 0x13cf18f0b540004, negotiated timeout = 10000
[junit4:junit4] 2> 3385 T3064 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e2923 name:ZooKeeperConnection Watcher:127.0.0.1:39739/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3385 T3036 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3386 T3036 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 3387 T3036 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 3433 T3036 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 3434 T3036 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53554
[junit4:junit4] 2> 3435 T3036 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 3435 T3036 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 3436 T3036 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361262352521
[junit4:junit4] 2> 3436 T3036 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361262352521/solr.xml
[junit4:junit4] 2> 3436 T3036 oasc.CoreContainer.<init> New CoreContainer 11484516
[junit4:junit4] 2> 3437 T3036 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361262352521/'
[junit4:junit4] 2> 3437 T3036 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361262352521/'
[junit4:junit4] 2> 3451 T3036 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 3451 T3036 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 3452 T3036 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 3452 T3036 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 3452 T3036 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 3452 T3036 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 3453 T3036 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 3453 T3036 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 3454 T3036 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 3454 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 3459 T3036 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 3467 T3036 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:39739/solr
[junit4:junit4] 2> 3467 T3036 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 3468 T3036 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39739 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@173d4d7
[junit4:junit4] 2> 3468 T3036 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3469 T3074 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:39739. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3469 T3074 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:39739, initiating session
[junit4:junit4] 2> 3469 T3038 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51243
[junit4:junit4] 2> 3469 T3038 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51243
[junit4:junit4] 2> 3470 T3040 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf18f0b540005 with negotiated timeout 20000 for client /127.0.0.1:51243
[junit4:junit4] 2> 3470 T3074 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:39739, sessionid = 0x13cf18f0b540005, negotiated timeout = 20000
[junit4:junit4] 2> 3470 T3075 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@173d4d7 name:ZooKeeperConnection Watcher:127.0.0.1:39739 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3470 T3036 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3471 T3041 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf18f0b540005
[junit4:junit4] 2> 3471 T3075 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 3471 T3038 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:51243 which had sessionid 0x13cf18f0b540005
[junit4:junit4] 2> 3471 T3036 oaz.ZooKeeper.close Session: 0x13cf18f0b540005 closed
[junit4:junit4] 2> 3472 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 3474 T3036 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39739/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@f592af
[junit4:junit4] 2> 3475 T3076 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:39739. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3475 T3036 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3475 T3076 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:39739, initiating session
[junit4:junit4] 2> 3475 T3038 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51244
[junit4:junit4] 2> 3475 T3038 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51244
[junit4:junit4] 2> 3476 T3040 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf18f0b540006 with negotiated timeout 20000 for client /127.0.0.1:51244
[junit4:junit4] 2> 3476 T3076 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:39739, sessionid = 0x13cf18f0b540006, negotiated timeout = 20000
[junit4:junit4] 2> 3476 T3077 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f592af name:ZooKeeperConnection Watcher:127.0.0.1:39739/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3476 T3036 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3477 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540006 type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3477 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540006 type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3478 T3036 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 4480 T3036 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53554_ws_whv
[junit4:junit4] 2> 4480 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540006 type:delete cxid:0x9 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:53554_ws_whv Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:53554_ws_whv
[junit4:junit4] 2> 4481 T3036 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53554_ws_whv
[junit4:junit4] 2> 4482 T3064 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4482 T3077 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4482 T3058 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4483 T3058 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> 4486 T3078 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361262352521/collection1
[junit4:junit4] 2> 4487 T3078 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 4487 T3078 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 4487 T3078 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 4488 T3078 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361262352521/collection1/'
[junit4:junit4] 2> 4497 T3078 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361262352521/collection1/lib/README' to classloader
[junit4:junit4] 2> 4498 T3078 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361262352521/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 4517 T3078 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 4543 T3078 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 4544 T3078 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 4547 T3078 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 4817 T3078 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 4822 T3078 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 4824 T3078 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 4831 T3078 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 4833 T3078 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 4836 T3078 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 4836 T3078 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 4837 T3078 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361262352521/collection1/, dataDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty1/
[junit4:junit4] 2> 4837 T3078 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@857f67
[junit4:junit4] 2> 4838 T3078 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 4839 T3078 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty1 forceNew:false
[junit4:junit4] 2> 4839 T3078 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty1
[junit4:junit4] 2> 4839 T3078 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty1/index/
[junit4:junit4] 2> 4840 T3078 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 4840 T3078 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty1/index forceNew:false
[junit4:junit4] 2> 4841 T3078 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@387d0d lockFactory=org.apache.lucene.store.NativeFSLockFactory@23f37d),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 4842 T3078 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 4842 T3078 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty1/index
[junit4:junit4] 2> 4843 T3078 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 4844 T3078 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 4844 T3078 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 4845 T3078 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 4845 T3078 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 4845 T3078 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 4845 T3078 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 4846 T3078 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 4846 T3078 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 4849 T3078 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 4850 T3059 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 4850 T3059 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "node_name":"127.0.0.1:32984_ws_whv",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:32984/ws_whv",
[junit4:junit4] 2> "shard":"shard1"}
[junit4:junit4] 2> 4851 T3078 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty1
[junit4:junit4] 2> 4852 T3078 oass.SolrIndexSearcher.<init> Opening Searcher@373c63 main
[junit4:junit4] 2> 4852 T3078 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty1/tlog
[junit4:junit4] 2> 4853 T3078 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 4853 T3078 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 4853 T3058 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> 4853 T3077 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> 4853 T3064 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> 4856 T3079 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@373c63 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 4857 T3078 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 4857 T3078 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 6356 T3059 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 6356 T3059 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "node_name":"127.0.0.1:53554_ws_whv",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53554/ws_whv",
[junit4:junit4] 2> "shard":null}
[junit4:junit4] 2> 6356 T3059 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 6357 T3059 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 6359 T3077 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> 6359 T3064 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> 6359 T3058 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> 6858 T3078 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 6858 T3078 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53554/ws_whv collection:collection1 shard:shard2
[junit4:junit4] 2> 6859 T3078 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 6864 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540006 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> 6865 T3078 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 6866 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540006 type:create cxid:0x47 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 6867 T3078 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 6868 T3078 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 6868 T3078 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53554/ws_whv/collection1/
[junit4:junit4] 2> 6868 T3078 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 6868 T3078 oasc.SyncStrategy.syncToMe http://127.0.0.1:53554/ws_whv/collection1/ has no replicas
[junit4:junit4] 2> 6868 T3078 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53554/ws_whv/collection1/
[junit4:junit4] 2> 6868 T3078 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 6874 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540006 type:create cxid:0x51 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 7862 T3059 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 7866 T3058 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> 7866 T3064 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> 7866 T3077 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> 7867 T3078 oasc.ZkController.register We are http://127.0.0.1:53554/ws_whv/collection1/ and leader is http://127.0.0.1:53554/ws_whv/collection1/
[junit4:junit4] 2> 7868 T3078 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53554/ws_whv
[junit4:junit4] 2> 7868 T3078 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 7868 T3078 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 7868 T3078 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 8256 T3078 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8257 T3036 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 8258 T3036 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 8258 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 8305 T3036 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 8307 T3036 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36916
[junit4:junit4] 2> 8308 T3036 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 8308 T3036 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 8309 T3036 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361262357394
[junit4:junit4] 2> 8309 T3036 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361262357394/solr.xml
[junit4:junit4] 2> 8310 T3036 oasc.CoreContainer.<init> New CoreContainer 21638999
[junit4:junit4] 2> 8310 T3036 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361262357394/'
[junit4:junit4] 2> 8311 T3036 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361262357394/'
[junit4:junit4] 2> 8327 T3036 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 8328 T3036 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 8328 T3036 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 8328 T3036 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 8328 T3036 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 8329 T3036 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 8329 T3036 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 8329 T3036 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 8330 T3036 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 8330 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 8335 T3036 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 8343 T3036 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:39739/solr
[junit4:junit4] 2> 8344 T3036 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 8344 T3036 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39739 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@aa17c8
[junit4:junit4] 2> 8345 T3036 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8345 T3089 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:39739. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 8345 T3089 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:39739, initiating session
[junit4:junit4] 2> 8345 T3038 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51257
[junit4:junit4] 2> 8346 T3038 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51257
[junit4:junit4] 2> 8347 T3040 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf18f0b540007 with negotiated timeout 20000 for client /127.0.0.1:51257
[junit4:junit4] 2> 8347 T3089 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:39739, sessionid = 0x13cf18f0b540007, negotiated timeout = 20000
[junit4:junit4] 2> 8347 T3090 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@aa17c8 name:ZooKeeperConnection Watcher:127.0.0.1:39739 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8347 T3036 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8348 T3041 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf18f0b540007
[junit4:junit4] 2> 8349 T3038 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:51257 which had sessionid 0x13cf18f0b540007
[junit4:junit4] 2> 8349 T3036 oaz.ZooKeeper.close Session: 0x13cf18f0b540007 closed
[junit4:junit4] 2> 8349 T3090 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 8349 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 8352 T3036 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39739/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1b3847b
[junit4:junit4] 2> 8352 T3091 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:39739. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 8352 T3036 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8353 T3091 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:39739, initiating session
[junit4:junit4] 2> 8353 T3038 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51258
[junit4:junit4] 2> 8353 T3038 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51258
[junit4:junit4] 2> 8353 T3040 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf18f0b540008 with negotiated timeout 20000 for client /127.0.0.1:51258
[junit4:junit4] 2> 8353 T3091 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:39739, sessionid = 0x13cf18f0b540008, negotiated timeout = 20000
[junit4:junit4] 2> 8354 T3092 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b3847b name:ZooKeeperConnection Watcher:127.0.0.1:39739/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8354 T3036 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8354 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540008 type:create cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8355 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540008 type:create cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8356 T3036 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 9357 T3036 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36916_ws_whv
[junit4:junit4] 2> 9358 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540008 type:delete cxid:0x9 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:36916_ws_whv Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:36916_ws_whv
[junit4:junit4] 2> 9359 T3036 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36916_ws_whv
[junit4:junit4] 2> 9360 T3058 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> 9360 T3064 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> 9361 T3077 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9361 T3092 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9361 T3077 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> 9362 T3064 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9362 T3058 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9365 T3093 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361262357394/collection1
[junit4:junit4] 2> 9365 T3093 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 9366 T3093 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 9366 T3093 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 9367 T3093 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361262357394/collection1/'
[junit4:junit4] 2> 9367 T3093 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361262357394/collection1/lib/README' to classloader
[junit4:junit4] 2> 9367 T3093 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361262357394/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 9387 T3093 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 9411 T3093 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 9412 T3093 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 9415 T3093 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 9677 T3093 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 9682 T3093 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 9684 T3093 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 9690 T3093 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 9692 T3093 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 9694 T3093 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 9695 T3093 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 9695 T3093 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361262357394/collection1/, dataDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty2/
[junit4:junit4] 2> 9696 T3093 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@857f67
[junit4:junit4] 2> 9696 T3093 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 9697 T3093 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty2 forceNew:false
[junit4:junit4] 2> 9697 T3093 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty2
[junit4:junit4] 2> 9697 T3093 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty2/index/
[junit4:junit4] 2> 9698 T3093 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 9698 T3093 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty2/index forceNew:false
[junit4:junit4] 2> 9699 T3093 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1747dd4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4458a1),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 9699 T3093 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 9700 T3093 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty2/index
[junit4:junit4] 2> 9700 T3093 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 9701 T3093 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 9701 T3093 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 9701 T3093 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 9702 T3093 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 9702 T3093 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 9702 T3093 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 9702 T3093 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 9702 T3093 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 9704 T3093 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 9706 T3093 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty2
[junit4:junit4] 2> 9706 T3093 oass.SolrIndexSearcher.<init> Opening Searcher@10a5658 main
[junit4:junit4] 2> 9706 T3093 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty2/tlog
[junit4:junit4] 2> 9707 T3093 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 9707 T3093 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 9709 T3094 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@10a5658 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 9710 T3093 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 9710 T3093 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 9757 T3059 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 9758 T3059 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "node_name":"127.0.0.1:53554_ws_whv",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53554/ws_whv",
[junit4:junit4] 2> "shard":"shard2"}
[junit4:junit4] 2> 9759 T3059 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "node_name":"127.0.0.1:36916_ws_whv",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36916/ws_whv",
[junit4:junit4] 2> "shard":null}
[junit4:junit4] 2> 9759 T3059 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 9759 T3059 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 9761 T3077 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> 9761 T3058 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> 9761 T3092 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> 9761 T3064 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> 10711 T3093 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 10711 T3093 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36916/ws_whv collection:collection1 shard:shard1
[junit4:junit4] 2> 10712 T3093 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 10715 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540008 type:delete cxid:0x43 zxid:0x7d txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard1 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard1
[junit4:junit4] 2> 10716 T3093 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 10716 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540008 type:create cxid:0x44 zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 10717 T3093 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 10717 T3093 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 10717 T3093 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:36916/ws_whv/collection1/
[junit4:junit4] 2> 10717 T3093 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 10717 T3093 oasc.SyncStrategy.syncToMe http://127.0.0.1:36916/ws_whv/collection1/ has no replicas
[junit4:junit4] 2> 10717 T3093 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:36916/ws_whv/collection1/
[junit4:junit4] 2> 10718 T3093 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 10719 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540008 type:create cxid:0x4d zxid:0x81 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 11264 T3059 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 11277 T3064 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> 11277 T3092 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> 11277 T3058 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> 11277 T3077 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> 11326 T3093 oasc.ZkController.register We are http://127.0.0.1:36916/ws_whv/collection1/ and leader is http://127.0.0.1:36916/ws_whv/collection1/
[junit4:junit4] 2> 11326 T3093 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36916/ws_whv
[junit4:junit4] 2> 11326 T3093 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 11327 T3093 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 11327 T3093 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 11328 T3093 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 11329 T3036 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 11329 T3036 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 11330 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 11389 T3036 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 11391 T3036 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58859
[junit4:junit4] 2> 11391 T3036 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 11392 T3036 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 11392 T3036 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361262360467
[junit4:junit4] 2> 11393 T3036 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361262360467/solr.xml
[junit4:junit4] 2> 11393 T3036 oasc.CoreContainer.<init> New CoreContainer 19177716
[junit4:junit4] 2> 11393 T3036 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361262360467/'
[junit4:junit4] 2> 11394 T3036 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361262360467/'
[junit4:junit4] 2> 11409 T3036 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 11410 T3036 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 11410 T3036 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 11411 T3036 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 11411 T3036 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 11411 T3036 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 11412 T3036 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 11412 T3036 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 11412 T3036 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 11412 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 11418 T3036 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 11426 T3036 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:39739/solr
[junit4:junit4] 2> 11427 T3036 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 11427 T3036 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39739 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@ba0425
[junit4:junit4] 2> 11428 T3104 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:39739. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 11428 T3036 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 11428 T3104 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:39739, initiating session
[junit4:junit4] 2> 11428 T3038 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51264
[junit4:junit4] 2> 11428 T3038 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51264
[junit4:junit4] 2> 11429 T3040 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf18f0b540009 with negotiated timeout 20000 for client /127.0.0.1:51264
[junit4:junit4] 2> 11429 T3104 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:39739, sessionid = 0x13cf18f0b540009, negotiated timeout = 20000
[junit4:junit4] 2> 11429 T3105 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ba0425 name:ZooKeeperConnection Watcher:127.0.0.1:39739 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 11429 T3036 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 11430 T3041 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf18f0b540009
[junit4:junit4] 2> 11431 T3105 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 11431 T3038 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:51264 which had sessionid 0x13cf18f0b540009
[junit4:junit4] 2> 11431 T3036 oaz.ZooKeeper.close Session: 0x13cf18f0b540009 closed
[junit4:junit4] 2> 11431 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 11433 T3036 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39739/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1478961
[junit4:junit4] 2> 11434 T3106 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:39739. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 11434 T3036 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 11434 T3038 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51265
[junit4:junit4] 2> 11434 T3106 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:39739, initiating session
[junit4:junit4] 2> 11435 T3038 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51265
[junit4:junit4] 2> 11435 T3040 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf18f0b54000a with negotiated timeout 20000 for client /127.0.0.1:51265
[junit4:junit4] 2> 11435 T3106 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:39739, sessionid = 0x13cf18f0b54000a, negotiated timeout = 20000
[junit4:junit4] 2> 11435 T3107 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1478961 name:ZooKeeperConnection Watcher:127.0.0.1:39739/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 11436 T3036 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 11436 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b54000a type:create cxid:0x1 zxid:0x8e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 11437 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b54000a type:create cxid:0x2 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 11437 T3036 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 12439 T3036 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58859_ws_whv
[junit4:junit4] 2> 12440 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b54000a type:delete cxid:0x9 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:58859_ws_whv Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:58859_ws_whv
[junit4:junit4] 2> 12445 T3036 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58859_ws_whv
[junit4:junit4] 2> 12447 T3077 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> 12447 T3058 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> 12448 T3064 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 12448 T3092 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 12448 T3107 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 12448 T3064 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> 12448 T3092 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> 12448 T3077 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 12449 T3058 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 12453 T3108 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361262360467/collection1
[junit4:junit4] 2> 12453 T3108 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 12454 T3108 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 12454 T3108 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 12455 T3108 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361262360467/collection1/'
[junit4:junit4] 2> 12455 T3108 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361262360467/collection1/lib/README' to classloader
[junit4:junit4] 2> 12455 T3108 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361262360467/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 12474 T3108 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 12499 T3108 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 12500 T3108 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 12503 T3108 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 12770 T3108 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 12775 T3108 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 12777 T3108 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 12780 T3059 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 12781 T3059 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "node_name":"127.0.0.1:36916_ws_whv",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36916/ws_whv",
[junit4:junit4] 2> "shard":"shard1"}
[junit4:junit4] 2> 12783 T3058 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> 12783 T3092 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> 12783 T3077 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> 12783 T3064 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> 12784 T3107 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> 12786 T3108 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 12788 T3108 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 12790 T3108 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 12790 T3108 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 12791 T3108 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1361262360467/collection1/, dataDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3/
[junit4:junit4] 2> 12791 T3108 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@857f67
[junit4:junit4] 2> 12792 T3108 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 12792 T3108 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3 forceNew:false
[junit4:junit4] 2> 12793 T3108 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3
[junit4:junit4] 2> 12793 T3108 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3/index/
[junit4:junit4] 2> 12793 T3108 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 12793 T3108 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3/index forceNew:false
[junit4:junit4] 2> 12794 T3108 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@10670f2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@121dd5b),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 12794 T3108 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 12795 T3108 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3/index
[junit4:junit4] 2> 12796 T3108 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 12796 T3108 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 12796 T3108 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 12796 T3108 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 12797 T3108 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 12797 T3108 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 12797 T3108 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 12797 T3108 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 12797 T3108 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 12799 T3108 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 12801 T3108 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3
[junit4:junit4] 2> 12801 T3108 oass.SolrIndexSearcher.<init> Opening Searcher@c73a16 main
[junit4:junit4] 2> 12802 T3108 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3/tlog
[junit4:junit4] 2> 12802 T3108 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 12802 T3108 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 12806 T3109 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c73a16 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 12807 T3108 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 12807 T3108 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 14286 T3059 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 14287 T3059 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "node_name":"127.0.0.1:58859_ws_whv",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58859/ws_whv",
[junit4:junit4] 2> "shard":null}
[junit4:junit4] 2> 14287 T3059 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 14287 T3059 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 14291 T3092 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> 14291 T3064 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> 14291 T3107 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> 14291 T3077 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> 14291 T3058 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> 14808 T3108 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 14809 T3108 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58859/ws_whv collection:collection1 shard:shard2
[junit4:junit4] 2> 14811 T3108 oasc.ZkController.register We are http://127.0.0.1:58859/ws_whv/collection1/ and leader is http://127.0.0.1:53554/ws_whv/collection1/
[junit4:junit4] 2> 14811 T3108 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58859/ws_whv
[junit4:junit4] 2> 14811 T3108 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 14812 T3108 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C267 name=collection1 org.apache.solr.core.SolrCore@72a6b2 url=http://127.0.0.1:58859/ws_whv/collection1 node=127.0.0.1:58859_ws_whv C267_STATE=coll:collection1 core:collection1 props:{node_name=127.0.0.1:58859_ws_whv, core=collection1, roles=null, state=down, collection=collection1, base_url=http://127.0.0.1:58859/ws_whv, shard=null}
[junit4:junit4] 2> 14812 T3110 C267 P58859 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 14813 T3110 C267 P58859 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 14813 T3108 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 14813 T3110 C267 P58859 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 14813 T3110 C267 P58859 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 14813 T3036 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 14814 T3110 C267 P58859 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 14814 T3036 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 14814 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 14863 T3036 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 14865 T3036 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:41893
[junit4:junit4] 2> 14865 T3036 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 14865 T3036 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 14866 T3036 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361262363951
[junit4:junit4] 2> 14866 T3036 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361262363951/solr.xml
[junit4:junit4] 2> 14866 T3036 oasc.CoreContainer.<init> New CoreContainer 31437147
[junit4:junit4] 2> 14867 T3036 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361262363951/'
[junit4:junit4] 2> 14867 T3036 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361262363951/'
[junit4:junit4] 2> 14881 T3036 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 14881 T3036 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 14882 T3036 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 14882 T3036 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 14882 T3036 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 14882 T3036 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 14883 T3036 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 14883 T3036 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 14883 T3036 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 14884 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 14889 T3036 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 14897 T3036 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:39739/solr
[junit4:junit4] 2> 14897 T3036 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 14898 T3036 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39739 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1d53ac6
[junit4:junit4] 2> 14899 T3036 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 14899 T3120 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:39739. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 14899 T3120 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:39739, initiating session
[junit4:junit4] 2> 14899 T3038 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51268
[junit4:junit4] 2> 14900 T3038 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51268
[junit4:junit4] 2> 14900 T3040 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf18f0b54000b with negotiated timeout 20000 for client /127.0.0.1:51268
[junit4:junit4] 2> 14900 T3120 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:39739, sessionid = 0x13cf18f0b54000b, negotiated timeout = 20000
[junit4:junit4] 2> 14902 T3121 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d53ac6 name:ZooKeeperConnection Watcher:127.0.0.1:39739 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 14902 T3036 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 14903 T3041 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf18f0b54000b
[junit4:junit4] 2> 14904 T3121 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 14904 T3038 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:51268 which had sessionid 0x13cf18f0b54000b
[junit4:junit4] 2> 14904 T3036 oaz.ZooKeeper.close Session: 0x13cf18f0b54000b closed
[junit4:junit4] 2> 14904 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 14907 T3036 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39739/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@96e195
[junit4:junit4] 2> 14907 T3122 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:39739. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 14907 T3036 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 14908 T3122 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:39739, initiating session
[junit4:junit4] 2> 14908 T3038 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51269
[junit4:junit4] 2> 14908 T3038 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51269
[junit4:junit4] 2> 14908 T3040 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf18f0b54000c with negotiated timeout 20000 for client /127.0.0.1:51269
[junit4:junit4] 2> 14908 T3122 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:39739, sessionid = 0x13cf18f0b54000c, negotiated timeout = 20000
[junit4:junit4] 2> 14909 T3123 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@96e195 name:ZooKeeperConnection Watcher:127.0.0.1:39739/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 14909 T3036 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 14910 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b54000c type:create cxid:0x1 zxid:0xa1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 14910 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b54000c type:create cxid:0x2 zxid:0xa2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 14911 T3036 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 15794 T3059 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 15795 T3059 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "node_name":"127.0.0.1:58859_ws_whv",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58859/ws_whv",
[junit4:junit4] 2> "shard":"shard2"}
[junit4:junit4] 2> 15798 T3077 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> 15798 T3092 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> 15798 T3123 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> 15798 T3064 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> 15798 T3058 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> 15798 T3107 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> 15913 T3036 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41893_ws_whv
[junit4:junit4] 2> 15914 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b54000c type:delete cxid:0xb zxid:0xa7 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:41893_ws_whv Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:41893_ws_whv
[junit4:junit4] 2> 15914 T3036 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:41893_ws_whv
[junit4:junit4] 2> 15916 T3077 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> 15916 T3123 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> 15916 T3107 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> 15916 T3064 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 15916 T3058 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 15917 T3058 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> 15916 T3064 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> 15916 T3092 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 15917 T3092 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> 15917 T3077 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 15917 T3107 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 15918 T3123 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 15921 T3124 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361262363951/collection1
[junit4:junit4] 2> 15921 T3124 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 15922 T3124 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 15922 T3124 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 15922 T3124 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361262363951/collection1/'
[junit4:junit4] 2> 15923 T3124 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361262363951/collection1/lib/README' to classloader
[junit4:junit4] 2> 15923 T3124 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361262363951/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 15942 T3124 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 15968 T3124 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 15969 T3124 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 15971 T3124 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 16247 T3124 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 16252 T3124 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 16254 T3124 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 16260 T3124 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 16262 T3124 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 16264 T3124 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 16265 T3124 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 16266 T3124 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1361262363951/collection1/, dataDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4/
[junit4:junit4] 2> 16266 T3124 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@857f67
[junit4:junit4] 2> 16266 T3124 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 16267 T3124 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4 forceNew:false
[junit4:junit4] 2> 16267 T3124 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4
[junit4:junit4] 2> 16267 T3124 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4/index/
[junit4:junit4] 2> 16268 T3124 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 16268 T3124 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4/index forceNew:false
[junit4:junit4] 2> 16269 T3124 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@ba3fd7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@14061cf),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 16269 T3124 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 16269 T3124 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4/index
[junit4:junit4] 2> 16270 T3124 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 16270 T3124 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 16270 T3124 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 16271 T3124 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 16271 T3124 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 16271 T3124 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 16271 T3124 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 16272 T3124 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 16272 T3124 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 16274 T3124 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 16275 T3124 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4
[junit4:junit4] 2> 16276 T3124 oass.SolrIndexSearcher.<init> Opening Searcher@1b00a7b main
[junit4:junit4] 2> 16276 T3124 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4/tlog
[junit4:junit4] 2> 16276 T3124 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 16277 T3124 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 16279 T3125 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b00a7b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 16280 T3124 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 16280 T3124 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 17301 T3059 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 17302 T3059 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "node_name":"127.0.0.1:41893_ws_whv",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:41893/ws_whv",
[junit4:junit4] 2> "shard":null}
[junit4:junit4] 2> 17302 T3059 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 17302 T3059 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 17304 T3064 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> 17304 T3123 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> 17305 T3107 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> 17305 T3077 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> 17304 T3092 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> 17304 T3058 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> C267_STATE=coll:collection1 core:collection1 props:{node_name=127.0.0.1:58859_ws_whv, core=collection1, roles=null, state=recovering, collection=collection1, base_url=http://127.0.0.1:58859/ws_whv, shard=shard2}
[junit4:junit4] 2> 17818 T3110 C267 P58859 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:53554/ws_whv/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 17818 T3110 C267 P58859 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:58859/ws_whv START replicas=[http://127.0.0.1:53554/ws_whv/collection1/] nUpdates=100
[junit4:junit4] 2> 17819 T3110 C267 P58859 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 17819 T3110 C267 P58859 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 17819 T3110 C267 P58859 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 17819 T3110 C267 P58859 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 17819 T3110 C267 P58859 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 17819 T3110 C267 P58859 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:53554/ws_whv/collection1/. core=collection1
[junit4:junit4] 2> 17819 T3110 C267 P58859 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C268 name=collection1 org.apache.solr.core.SolrCore@140f676 url=http://127.0.0.1:53554/ws_whv/collection1 node=127.0.0.1:53554_ws_whv C268_STATE=coll:collection1 core:collection1 props:{node_name=127.0.0.1:53554_ws_whv, core=collection1, roles=null, state=active, collection=collection1, base_url=http://127.0.0.1:53554/ws_whv, shard=shard2, leader=true}
[junit4:junit4] 2> 17822 T3070 C268 P53554 REQ /get {distrib=false&qt=/get&wt=javabin&getVersions=100&version=2} status=0 QTime=0
[junit4:junit4] 2> 17822 T3073 C268 P53554 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4] 2> 17823 T3073 C268 P53554 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty1
[junit4:junit4] 2> 17824 T3073 C268 P53554 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@387d0d lockFactory=org.apache.lucene.store.NativeFSLockFactory@23f37d),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 17825 T3073 C268 P53554 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 17825 T3073 C268 P53554 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@387d0d lockFactory=org.apache.lucene.store.NativeFSLockFactory@23f37d),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@387d0d lockFactory=org.apache.lucene.store.NativeFSLockFactory@23f37d),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 17826 T3073 C268 P53554 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 17826 T3073 C268 P53554 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty1
[junit4:junit4] 2> 17826 T3073 C268 P53554 oass.SolrIndexSearcher.<init> Opening Searcher@e6e1b1 realtime
[junit4:junit4] 2> 17826 T3073 C268 P53554 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 17827 T3073 C268 P53554 /update {commit_end_point=true&openSearcher=false&commit=true&wt=javabin&waitSearcher=true&softCommit=false&version=2} {commit=} 0 5
[junit4:junit4] 2> 17827 T3110 C267 P58859 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 17827 T3110 C267 P58859 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 17831 T3071 C268 P53554 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 17831 T3071 C268 P53554 REQ /replication {qt=/replication&wt=javabin&command=indexversion&version=2} status=0 QTime=3
[junit4:junit4] 2> 17831 T3110 C267 P58859 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 17832 T3110 C267 P58859 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 17832 T3110 C267 P58859 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 17833 T3070 C268 P53554 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty1
[junit4:junit4] 2> 17833 T3070 C268 P53554 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty1/index
[junit4:junit4] 2> 17834 T3070 C268 P53554 REQ /replication {generation=2&qt=/replication&wt=javabin&command=filelist&version=2} status=0 QTime=1
[junit4:junit4] 2> 17834 T3110 C267 P58859 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 17835 T3110 C267 P58859 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3/index.20130219102606968 forceNew:false
[junit4:junit4] 2> 17835 T3110 C267 P58859 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3
[junit4:junit4] 2> 17835 T3110 C267 P58859 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/index2995729982tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@1557e31) fullCopy=true
[junit4:junit4] 2> 17837 T3073 C268 P53554 REQ /replication {file=segments_2&generation=2&qt=/replication&wt=filestream&checksum=true&command=filecontent} status=0 QTime=0
[junit4:junit4] 2> 17838 T3110 C267 P58859 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3/index
[junit4:junit4] 2> 17838 T3110 C267 P58859 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 17839 T3110 C267 P58859 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130219102606968
[junit4:junit4] 2> 17839 T3110 C267 P58859 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3
[junit4:junit4] 2> 17840 T3110 C267 P58859 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3
[junit4:junit4] 2> 17840 T3110 C267 P58859 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3/index/ new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3/index.20130219102606968
[junit4:junit4] 2> 17841 T3110 C267 P58859 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/index2995729982tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@1557e31),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 17841 T3110 C267 P58859 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 17841 T3110 C267 P58859 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3
[junit4:junit4] 2> 17841 T3110 C267 P58859 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 17842 T3110 C267 P58859 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 17842 T3110 C267 P58859 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4] 2> 17842 T3110 C267 P58859 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3/index.20130219102606968
[junit4:junit4] 2> 17842 T3110 C267 P58859 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3
[junit4:junit4] 2> 17843 T3110 C267 P58859 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/index2995729982tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@1557e31),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 17843 T3110 C267 P58859 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 17843 T3110 C267 P58859 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 17843 T3110 C267 P58859 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3
[junit4:junit4] 2> 17844 T3110 C267 P58859 oass.SolrIndexSearcher.<init> Opening Searcher@6dc5d1 main
[junit4:junit4] 2> 17844 T3109 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6dc5d1 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 17844 T3109 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3/index
[junit4:junit4] 2> 17844 T3110 C267 P58859 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=false,expungeDeletes=false,softCommit=false}
[junit4:junit4] 2> 17846 T3110 C267 P58859 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/index2995729982tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@1557e31),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/index2995729982tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@1557e31),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4] 2> 17847 T3110 C267 P58859 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[segments_3]
[junit4:junit4] 2> 17847 T3110 C267 P58859 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3
[junit4:junit4] 2> 17847 T3110 C267 P58859 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 17847 T3110 C267 P58859 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3/index.20130219102606968
[junit4:junit4] 2> 17847 T3110 C267 P58859 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty3/index
[junit4:junit4] 2> 17847 T3110 C267 P58859 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 17847 T3110 C267 P58859 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 17848 T3110 C267 P58859 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 17848 T3110 C267 P58859 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 17848 T3110 C267 P58859 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 18281 T3124 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 18281 T3124 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:41893/ws_whv collection:collection1 shard:shard1
[junit4:junit4] 2> 18283 T3124 oasc.ZkController.register We are http://127.0.0.1:41893/ws_whv/collection1/ and leader is http://127.0.0.1:36916/ws_whv/collection1/
[junit4:junit4] 2> 18283 T3124 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:41893/ws_whv
[junit4:junit4] 2> 18283 T3124 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 18284 T3124 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C269 name=collection1 org.apache.solr.core.SolrCore@14bb4df url=http://127.0.0.1:41893/ws_whv/collection1 node=127.0.0.1:41893_ws_whv C269_STATE=coll:collection1 core:collection1 props:{node_name=127.0.0.1:41893_ws_whv, core=collection1, roles=null, state=down, collection=collection1, base_url=http://127.0.0.1:41893/ws_whv, shard=null}
[junit4:junit4] 2> 18284 T3128 C269 P41893 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 18285 T3128 C269 P41893 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 18285 T3124 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 18285 T3128 C269 P41893 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 18285 T3128 C269 P41893 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 18285 T3036 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 18286 T3128 C269 P41893 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 18286 T3036 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 18287 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 18290 T3036 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 18291 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 18295 T3070 oasc.CoreContainer.create Creating SolrCore 'unloadcollection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361262352521/unloadcollection1
[junit4:junit4] 2> 18295 T3070 oasc.ZkController.createCollectionZkNode Check for collection zkNode:unloadcollection
[junit4:junit4] 2> 18295 T3070 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:unloadcollection
[junit4:junit4] 2> 18296 T3070 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 18296 T3070 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 18296 T3070 oascc.SolrZkClient.makePath makePath: /collections/unloadcollection
[junit4:junit4] 2> 18298 T3070 oasc.ZkController.readConfigName Load collection config from:/collections/unloadcollection
[junit4:junit4] 2> 18298 T3070 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361262352521/unloadcollection1/'
[junit4:junit4] 2> 18323 T3070 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 18352 T3070 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 18353 T3070 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 18356 T3070 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 18661 T3070 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 18665 T3070 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 18667 T3070 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 18674 T3070 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 18676 T3070 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 18678 T3070 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 18679 T3070 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 18679 T3070 oasc.SolrCore.<init> [unloadcollection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361262352521/unloadcollection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262367428unloadcollection1_1n/
[junit4:junit4] 2> 18680 T3070 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@857f67
[junit4:junit4] 2> 18680 T3070 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 18681 T3070 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262367428unloadcollection1_1n forceNew:false
[junit4:junit4] 2> 18681 T3070 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262367428unloadcollection1_1n
[junit4:junit4] 2> 18682 T3070 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262367428unloadcollection1_1n/index/
[junit4:junit4] 2> 18682 T3070 oasc.SolrCore.initIndex WARNING [unloadcollection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262367428unloadcollection1_1n/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 18682 T3070 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262367428unloadcollection1_1n/index forceNew:false
[junit4:junit4] 2> 18683 T3070 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1608f8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@418002),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 18683 T3070 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 18684 T3070 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262367428unloadcollection1_1n/index
[junit4:junit4] 2> 18685 T3070 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 18685 T3070 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 18685 T3070 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 18686 T3070 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 18686 T3070 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 18686 T3070 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 18687 T3070 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 18687 T3070 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 18687 T3070 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 18689 T3070 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 18691 T3070 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262367428unloadcollection1_1n
[junit4:junit4] 2> 18691 T3070 oass.SolrIndexSearcher.<init> Opening Searcher@d2139d main
[junit4:junit4] 2> 18692 T3070 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262367428unloadcollection1_1n/tlog
[junit4:junit4] 2> 18692 T3070 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 18692 T3070 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 18694 T3070 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262367428unloadcollection1_1n
[junit4:junit4] 2> 18695 T3129 oasc.SolrCore.registerSearcher [unloadcollection1] Registered new searcher Searcher@d2139d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 18695 T3070 oasc.ZkController.publish publishing core=unloadcollection1 state=down
[junit4:junit4] 2> 18808 T3059 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 18809 T3059 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "node_name":"127.0.0.1:58859_ws_whv",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58859/ws_whv",
[junit4:junit4] 2> "shard":"shard2"}
[junit4:junit4] 2> 18812 T3059 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "node_name":"127.0.0.1:41893_ws_whv",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:41893/ws_whv",
[junit4:junit4] 2> "shard":"shard1"}
[junit4:junit4] 2> 18813 T3059 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "node_name":"127.0.0.1:53554_ws_whv",
[junit4:junit4] 2> "core":"unloadcollection1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "collection":"unloadcollection",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53554/ws_whv",
[junit4:junit4] 2> "shard":null}
[junit4:junit4] 2> 18813 T3059 oasc.Overseer$ClusterStateUpdater.createCollection Create collection unloadcollection with numShards 1
[junit4:junit4] 2> 18814 T3059 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 18818 T3077 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> 18818 T3092 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> 18818 T3058 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> 18818 T3064 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> 18818 T3107 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> 18818 T3123 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> 19697 T3070 oasc.CoreContainer.registerCore registering core: unloadcollection1
[junit4:junit4] 2> 19697 T3070 oasc.ZkController.register Register replica - core:unloadcollection1 address:http://127.0.0.1:53554/ws_whv collection:unloadcollection shard:shard1
[junit4:junit4] 2> 19698 T3070 oascc.SolrZkClient.makePath makePath: /collections/unloadcollection/leader_elect/shard1/election
[junit4:junit4] 2> 19702 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540006 type:delete cxid:0xa4 zxid:0xc2 txntype:-1 reqpath:n/a Error Path:/solr/collections/unloadcollection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/unloadcollection/leaders
[junit4:junit4] 2> 19702 T3070 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 19703 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540006 type:create cxid:0xa5 zxid:0xc3 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 19704 T3070 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 19704 T3070 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 19705 T3070 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53554/ws_whv/unloadcollection1/
[junit4:junit4] 2> 19705 T3070 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 19705 T3070 oasc.SyncStrategy.syncToMe http://127.0.0.1:53554/ws_whv/unloadcollection1/ has no replicas
[junit4:junit4] 2> 19706 T3070 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53554/ws_whv/unloadcollection1/
[junit4:junit4] 2> 19706 T3070 oascc.SolrZkClient.makePath makePath: /collections/unloadcollection/leaders/shard1
[junit4:junit4] 2> 19709 T3041 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf18f0b540006 type:create cxid:0xaf zxid:0xc7 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 20323 T3059 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 21038 T3092 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> 21038 T3064 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> 21038 T3107 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> 21038 T3058 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> 21038 T3123 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> 21038 T3077 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> 21063 T3070 oasc.ZkController.register We are http://127.0.0.1:53554/ws_whv/unloadcollection1/ and leader is http://127.0.0.1:53554/ws_whv/unloadcollection1/
[junit4:junit4] 2> 21063 T3070 oasc.ZkController.register No LogReplay needed for core=unloadcollection1 baseURL=http://127.0.0.1:53554/ws_whv
[junit4:junit4] 2> 21063 T3070 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 21064 T3070 oasc.ZkController.publish publishing core=unloadcollection1 state=active
[junit4:junit4] 2> 21065 T3070 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 21066 T3070 oasc.CoreContainer.persistFile Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361262352521/solr.xml
[junit4:junit4] 2> 21074 T3070 oasc.SolrXMLSerializer.persistFile Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1361262352521/solr.xml
[junit4:junit4] 2> 21075 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 21077 T3036 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39739/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@b712d2
[junit4:junit4] 2> 21077 T3130 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:39739. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 21077 T3036 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 21078 T3130 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:39739, initiating session
[junit4:junit4] 2> 21078 T3038 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51283
[junit4:junit4] 2> 21078 T3038 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51283
[junit4:junit4] 2> 21079 T3130 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:39739, sessionid = 0x13cf18f0b54000d, negotiated timeout = 10000
[junit4:junit4] 2> 21079 T3040 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf18f0b54000d with negotiated timeout 10000 for client /127.0.0.1:51283
[junit4:junit4] 2> 21079 T3131 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b712d2 name:ZooKeeperConnection Watcher:127.0.0.1:39739/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 21079 T3036 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 21080 T3036 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 21081 T3036 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 21082 T3036 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 21086 T3086 oasc.CoreContainer.create Creating SolrCore 'unloadcollection2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361262357394/unloadcollection2
[junit4:junit4] 2> 21086 T3086 oasc.ZkController.createCollectionZkNode Check for collection zkNode:unloadcollection
[junit4:junit4] 2> 21086 T3086 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 21087 T3086 oasc.ZkController.readConfigName Load collection config from:/collections/unloadcollection
[junit4:junit4] 2> 21087 T3086 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361262357394/unloadcollection2/'
[junit4:junit4] 2> 21112 T3086 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 21141 T3086 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 21142 T3086 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 21145 T3086 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> C269_STATE=coll:collection1 core:collection1 props:{node_name=127.0.0.1:41893_ws_whv, core=collection1, roles=null, state=recovering, collection=collection1, base_url=http://127.0.0.1:41893/ws_whv, shard=shard1}
[junit4:junit4] 2> 21291 T3128 C269 P41893 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:36916/ws_whv/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 21292 T3128 C269 P41893 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:41893/ws_whv START replicas=[http://127.0.0.1:36916/ws_whv/collection1/] nUpdates=100
[junit4:junit4] 2> 21292 T3128 C269 P41893 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 21292 T3128 C269 P41893 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 21292 T3128 C269 P41893 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 21292 T3128 C269 P41893 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 21293 T3128 C269 P41893 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 21293 T3128 C269 P41893 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:36916/ws_whv/collection1/. core=collection1
[junit4:junit4] 2> 21293 T3128 C269 P41893 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C270 name=collection1 org.apache.solr.core.SolrCore@bb7bb url=http://127.0.0.1:36916/ws_whv/collection1 node=127.0.0.1:36916_ws_whv C270_STATE=coll:collection1 core:collection1 props:{node_name=127.0.0.1:36916_ws_whv, core=collection1, roles=null, state=active, collection=collection1, base_url=http://127.0.0.1:36916/ws_whv, shard=shard1, leader=true}
[junit4:junit4] 2> 21297 T3088 C270 P36916 REQ /get {distrib=false&qt=/get&wt=javabin&getVersions=100&version=2} status=0 QTime=0
[junit4:junit4] 2> 21300 T3087 C270 P36916 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4] 2> 21300 T3087 C270 P36916 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty2
[junit4:junit4] 2> 21301 T3087 C270 P36916 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1747dd4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4458a1),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 21302 T3087 C270 P36916 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 21302 T3087 C270 P36916 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1747dd4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4458a1),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1747dd4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4458a1),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 21303 T3087 C270 P36916 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 21303 T3087 C270 P36916 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty2
[junit4:junit4] 2> 21304 T3087 C270 P36916 oass.SolrIndexSearcher.<init> Opening Searcher@533e2a realtime
[junit4:junit4] 2> 21304 T3087 C270 P36916 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 21305 T3087 C270 P36916 /update {commit_end_point=true&openSearcher=false&commit=true&wt=javabin&waitSearcher=true&softCommit=false&version=2} {commit=} 0 5
[junit4:junit4] 2> 21305 T3128 C269 P41893 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 21305 T3128 C269 P41893 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 21306 T3087 C270 P36916 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 21307 T3087 C270 P36916 REQ /replication {qt=/replication&wt=javabin&command=indexversion&version=2} status=0 QTime=1
[junit4:junit4] 2> 21307 T3128 C269 P41893 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 21307 T3128 C269 P41893 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 21307 T3128 C269 P41893 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 21309 T3085 C270 P36916 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty2
[junit4:junit4] 2> 21309 T3085 C270 P36916 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty2/index
[junit4:junit4] 2> 21310 T3085 C270 P36916 REQ /replication {generation=2&qt=/replication&wt=javabin&command=filelist&version=2} status=0 QTime=1
[junit4:junit4] 2> 21310 T3128 C269 P41893 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 21311 T3128 C269 P41893 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4/index.20130219102610444 forceNew:false
[junit4:junit4] 2> 21312 T3128 C269 P41893 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4
[junit4:junit4] 2> 21312 T3128 C269 P41893 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/index2995729984tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@16f47c) fullCopy=true
[junit4:junit4] 2> 21314 T3088 C270 P36916 REQ /replication {file=segments_2&generation=2&qt=/replication&wt=filestream&checksum=true&command=filecontent} status=0 QTime=0
[junit4:junit4] 2> 21315 T3128 C269 P41893 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4/index
[junit4:junit4] 2> 21315 T3128 C269 P41893 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 21316 T3128 C269 P41893 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130219102610444
[junit4:junit4] 2> 21316 T3128 C269 P41893 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4
[junit4:junit4] 2> 21317 T3128 C269 P41893 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4
[junit4:junit4] 2> 21317 T3128 C269 P41893 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4/index/ new=./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4/index.20130219102610444
[junit4:junit4] 2> 21318 T3128 C269 P41893 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/index2995729984tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@16f47c),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 21318 T3128 C269 P41893 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 21319 T3128 C269 P41893 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4
[junit4:junit4] 2> 21319 T3128 C269 P41893 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 21319 T3128 C269 P41893 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 21319 T3128 C269 P41893 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4] 2> 21319 T3128 C269 P41893 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4/index.20130219102610444
[junit4:junit4] 2> 21320 T3128 C269 P41893 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4
[junit4:junit4] 2> 21321 T3128 C269 P41893 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/index2995729984tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@16f47c),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 21321 T3128 C269 P41893 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 21321 T3128 C269 P41893 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 21321 T3128 C269 P41893 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4
[junit4:junit4] 2> 21322 T3128 C269 P41893 oass.SolrIndexSearcher.<init> Opening Searcher@8a57a8 main
[junit4:junit4] 2> 21322 T3125 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@8a57a8 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 21323 T3125 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4/index
[junit4:junit4] 2> 21323 T3128 C269 P41893 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=false,expungeDeletes=false,softCommit=false}
[junit4:junit4] 2> 21325 T3128 C269 P41893 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/index2995729984tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@16f47c),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/index2995729984tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@16f47c),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4] 2> 21325 T3128 C269 P41893 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[segments_3]
[junit4:junit4] 2> 21325 T3128 C269 P41893 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4
[junit4:junit4] 2> 21326 T3128 C269 P41893 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 21326 T3128 C269 P41893 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4/index.20130219102610444
[junit4:junit4] 2> 21326 T3128 C269 P41893 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361262349138/jetty4/index
[junit4:junit4] 2> 21326 T3128 C269 P41893 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 21326 T3128 C269 P41893 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 21326 T3128 C269 P41893 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 21327 T3128 C269 P41893 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 21327 T3128 C269 P41893 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 21471 T3086 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 21476 T3086 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 21478 T3086 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 21485 T3086 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 21489 T3086 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 21492 T3086 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 21493 T3086 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 21494 T3086 oasc.SolrCore.<init> [unloadcollection2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1361262357394/unloadcollection2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262370219unloadcollection1_2n/
[junit4:junit4] 2> 21494 T3086 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@857f67
[junit4:junit4] 2> 21494 T3086 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 21495 T3086 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262370219unloadcollection1_2n forceNew:false
[junit4:junit4] 2> 21496 T3086 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262370219unloadcollection1_2n
[junit4:junit4] 2> 21496 T3086 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262370219unloadcollection1_2n/index/
[junit4:junit4] 2> 21497 T3086 oasc.SolrCore.initIndex WARNING [unloadcollection2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262370219unloadcollection1_2n/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 21497 T3086 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262370219unloadcollection1_2n/index forceNew:false
[junit4:junit4] 2> 21498 T3086 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@14bbf7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@10fbe60),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 21499 T3086 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 21499 T3086 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262370219unloadcollection1_2n/index
[junit4:junit4] 2> 21501 T3086 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 21501 T3086 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 21502 T3086 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 21502 T3086 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 21503 T3086 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 21503 T3086 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 21503 T3086 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 21504 T3086 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 21504 T3086 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 21507 T3086 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 21510 T3086 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262370219unloadcollection1_2n
[junit4:junit4] 2> 21510 T3086 oass.SolrIndexSearcher.<init> Opening Searcher@6aee7 main
[junit4:junit4] 2> 21511 T3086 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361262349138/1361262370219unloadcollection1_2n/tlog
[junit4:junit4] 2> 21511 T3086 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 21512 T3086 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 21514 T3134 oasc.SolrCore.registerSearcher [unloadcollection2] Registered new searcher Searcher@6aee7 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 21515 T3086 oasc.ZkController.publish publishing core=unloadcollection2 state=down
[junit4:junit4] 2> 21516 T3086 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 22543 T3059 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 22544 T3059 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "node_name":"127.0.0.1:53554_ws_whv",
[junit4:junit4] 2> "core":"unloadcollection1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "collection":"unloadcollection",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53554/ws_whv",
[junit4:junit4] 2> "shard":"shard1"}
[junit4:junit4] 2> 22546 T3059 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "node_name":"127.0.0.1:41893_ws_whv",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:41893/ws_whv",
[junit4:junit4] 2> "shard":"shard1"}
[junit4:junit4] 2> 22605 T3059 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "node_name":"127.0.0.1:36916_ws_whv",
[junit4:junit4] 2> "core":"unloadcollection2",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "collection":"unloadcollection",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36916/ws_whv",
[junit4:junit4] 2> "shard":null}
[junit4:junit4] 2> 22606 T3059 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4] 2> 22606 T3059 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 22609 T3131 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> 22609 T3064 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> 22609 T3058 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> 22609 T3077 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> 22609 T3123 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> 22609 T3092 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> 22609 T3107 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> 23517 T3086 oasc.CoreContainer.registerCore registering core: unloadcollection2
[junit4:junit4] 2> 23518 T3086 oasc.ZkController.register Register replica - core:unloadcollection2 address:http://127.0.0.1:36916/ws_whv collection:unloadcollection shard:shard1
[junit4:junit4] 2> 23520 T3086 oasc.ZkController.register We are http://127.0.0.1:36916/ws_whv/unloadcollection2/ and leader is http://127.0.0.1:53554/ws_whv/unloadcollection1/
[junit4:junit4] 2> 23520 T3086 oasc.ZkControlle
[...truncated too long message...]
nit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4] > at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4:junit4] > at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4:junit4] > at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4] > at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4:junit4] > at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4] > at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4] > at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4] > at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] > at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4] > at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4] > at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4] > at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 136503 T3036 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 136514 T3035 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4] 2> 136866 T3039 oazs.SessionTrackerImpl.run SessionTrackerImpl exited loop!
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {range_facet_l=PostingsFormat(name=TestBloomFilteredLucene41Postings), a_si=PostingsFormat(name=SimpleText), _version_=PostingsFormat(name=TestBloomFilteredLucene41Postings), multiDefault=PostingsFormat(name=SimpleText), range_facet_si=PostingsFormat(name=SimpleText), a_t=PostingsFormat(name=TestBloomFilteredLucene41Postings), timestamp=PostingsFormat(name=TestBloomFilteredLucene41Postings), text=Pulsing41(freqCutoff=12 minBlockSize=50 maxBlockSize=125), intDefault=PostingsFormat(name=TestBloomFilteredLucene41Postings), range_facet_sl=Pulsing41(freqCutoff=12 minBlockSize=50 maxBlockSize=125), other_tl1=PostingsFormat(name=TestBloomFilteredLucene41Postings), id=PostingsFormat(name=Lucene41WithOrds)}, docValues:{}, sim=DefaultSimilarity, locale=es_UY, timezone=Africa/Blantyre
[junit4:junit4] 2> NOTE: Linux 3.2.0-37-generic i386/Oracle Corporation 1.8.0-ea (32-bit)/cpus=8,threads=2,free=138110616,total=305987584
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestDocSet, TestDistributedSearch, TestMergePolicyConfig, BasicFunctionalityTest, TestDistributedGrouping, ZkNodePropsTest, SpellingQueryConverterTest, TestMultiCoreConfBootstrap, OutputWriterTest, LegacyHTMLStripCharFilterTest, TestTrie, ZkSolrClientTest, UUIDFieldTest, RecoveryZkTest, CollectionsAPIDistributedZkTest, TestPhraseSuggestions, TestPropInject, PrimitiveFieldTypeTest, UpdateParamsTest, TestSolrIndexConfig, TestRecovery, TestArbitraryIndexDir, OpenExchangeRatesOrgProviderTest, TestPropInjectDefaults, BadIndexSchemaTest, LeaderElectionTest, TestReload, TestLazyCores, TestCSVLoader, TestRemoteStreaming, TestSolrCoreProperties, OverseerTest, SliceStateTest, TestHashPartitioner, TestSolrDeletionPolicy2, TestBM25SimilarityFactory, SolrCoreTest, ReturnFieldsTest, PrimUtilsTest, TestFunctionQuery, TestWriterPerf, LukeRequestHandlerTest, TestQueryUtils, IndexSchemaRuntimeFieldTest, SliceStateUpdateTest, StandardRequestHandlerTest, TestSolrXMLSerializer, BasicZkTest, DocumentAnalysisRequestHandlerTest, TestUpdate, TestUtils, TestCSVResponseWriter, PathHierarchyTokenizerFactoryTest, QueryParsingTest, TestFoldingMultitermQuery, DOMUtilTest, TestSurroundQueryParser, TestOmitPositions, DirectUpdateHandlerTest, TestValueSourceCache, DirectSolrSpellCheckerTest, TestPostingsSolrHighlighter, SpellCheckComponentTest, FullSolrCloudDistribCmdsTest, TestReplicationHandler, TestRealTimeGet, TestExtendedDismaxParser, SoftAutoCommitTest, AutoCommitTest, StatsComponentTest, TestJoin, IndexBasedSpellCheckerTest, TestRangeQuery, TestCoreContainer, TestSort, ConvertedLegacyTest, PeerSyncTest, SignatureUpdateProcessorFactoryTest, TestBinaryResponseWriter, TestJmxIntegration, HighlighterTest, TestIndexSearcher, SolrRequestParserTest, DirectSolrConnectionTest, CacheHeaderTest, QueryEqualityTest, PolyFieldTest, DocumentBuilderTest, MBeansHandlerTest, DistributedQueryElevationComponentTest, TestPseudoReturnFields, DisMaxRequestHandlerTest, IndexSchemaTest, TermsComponentTest, DistanceFunctionTest, SolrInfoMBeanTest, XsltUpdateRequestHandlerTest, TestPHPSerializedResponseWriter, XmlUpdateRequestHandlerTest, PingRequestHandlerTest, TermVectorComponentTest, TestSolrQueryParser, FastVectorHighlighterTest, TestReversedWildcardFilterFactory, DebugComponentTest, JSONWriterTest, RequestHandlersTest, SearchHandlerTest, RequiredFieldsTest, SuggesterFSTTest, CopyFieldTest, SuggesterTSTTest, SuggesterTest, CSVRequestHandlerTest, ShowFileRequestHandlerTest, TestSolrDeletionPolicy1, UpdateRequestProcessorFactoryTest, NoCacheHeaderTest, FieldMutatingUpdateProcessorTest, DefaultValueUpdateProcessorTest, TestQuerySenderListener, SolrIndexConfigTest, NumericFieldsTest, MultiTermTest, TestPerFieldSimilarity, TestLMJelinekMercerSimilarityFactory, TestCodecSupport, DateMathParserTest, PluginInfoTest, FileUtilsTest, DateFieldTest, TestLRUCache, RAMDirectoryFactoryTest, PreAnalyzedFieldTest, AnalysisAfterCoreReloadTest, ShardRoutingTest, UnloadDistributedZkTest]
[junit4:junit4] Completed on J1 in 137.03s, 1 test, 1 failure <<< FAILURES!
[...truncated 10 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:381: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:361: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:183: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1202: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:865: There were test failures: 255 suites, 1055 tests, 1 failure, 8 ignored (3 assumptions)
Total time: 35 minutes 26 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 32bit/jdk1.8.0-ea-b65 -server -XX:+UseParallelGC
Email was triggered for: Failure
Sending email for trigger: Failure