lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.8.0-ea-b79) - Build # 4626 - Still Failing!
Date Fri, 08 Mar 2013 16:33:33 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/4626/
Java: 64bit/jdk1.8.0-ea-b79 -XX:+UseConcMarkSweepGC

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


FAILED:  org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch

Error Message:
Server at http://127.0.0.1:60893/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update

Stack Trace:
org.apache.solr.common.SolrException: Server at http://127.0.0.1:60893/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
	at __randomizedtesting.SeedInfo.seed([6A68881E2A336321:EB8E06065D6C031D]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:375)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
	at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:200)
	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:89)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:487)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:722)




Build Log:
[...truncated 9176 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 0 T1953 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4]   2> 3 T1953 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1362759909607
[junit4:junit4]   2> 4 T1953 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 4 T1954 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 5 T1954 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 5 T1954 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4]   2> 5 T1954 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4]   2> 5 T1954 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 6 T1954 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4]   2> 104 T1953 oasc.ZkTestServer.run start zk server on port:42321
[junit4:junit4]   2> 105 T1953 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42321 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@4ab03eb9
[junit4:junit4]   2> 105 T1953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 106 T1959 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42321. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 106 T1959 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42321, initiating session
[junit4:junit4]   2> 106 T1955 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33495
[junit4:junit4]   2> 107 T1955 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33495
[junit4:junit4]   2> 107 T1957 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 208 T1957 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4ad200e90000 with negotiated timeout 10000 for client /127.0.0.1:33495
[junit4:junit4]   2> 208 T1959 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42321, sessionid = 0x13d4ad200e90000, negotiated timeout = 10000
[junit4:junit4]   2> 209 T1960 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ab03eb9 name:ZooKeeperConnection Watcher:127.0.0.1:42321 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 209 T1953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 210 T1953 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 213 T1958 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4ad200e90000
[junit4:junit4]   2> 213 T1960 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 214 T1955 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33495 which had sessionid 0x13d4ad200e90000
[junit4:junit4]   2> 213 T1953 oaz.ZooKeeper.close Session: 0x13d4ad200e90000 closed
[junit4:junit4]   2> 214 T1953 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42321/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@4477c99f
[junit4:junit4]   2> 215 T1953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 216 T1961 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42321. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 216 T1961 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42321, initiating session
[junit4:junit4]   2> 216 T1955 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33496
[junit4:junit4]   2> 216 T1955 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33496
[junit4:junit4]   2> 217 T1957 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4ad200e90001 with negotiated timeout 10000 for client /127.0.0.1:33496
[junit4:junit4]   2> 217 T1961 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42321, sessionid = 0x13d4ad200e90001, negotiated timeout = 10000
[junit4:junit4]   2> 217 T1962 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4477c99f name:ZooKeeperConnection Watcher:127.0.0.1:42321/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 217 T1953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 218 T1953 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 220 T1953 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 221 T1953 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 222 T1953 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 224 T1953 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 224 T1953 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 227 T1953 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 227 T1953 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 229 T1953 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 230 T1953 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 231 T1953 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 232 T1953 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 233 T1953 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 233 T1953 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 235 T1953 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 235 T1953 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 237 T1953 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 238 T1953 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 239 T1953 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 240 T1953 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 241 T1953 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 241 T1953 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 243 T1958 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4ad200e90001
[junit4:junit4]   2> 243 T1962 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 243 T1955 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33496 which had sessionid 0x13d4ad200e90001
[junit4:junit4]   2> 243 T1953 oaz.ZooKeeper.close Session: 0x13d4ad200e90001 closed
[junit4:junit4]   2> 299 T1953 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 303 T1953 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53028
[junit4:junit4]   2> 303 T1953 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 304 T1953 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 304 T1953 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362759909847
[junit4:junit4]   2> 304 T1953 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362759909847/solr.xml
[junit4:junit4]   2> 305 T1953 oasc.CoreContainer.<init> New CoreContainer 147752565
[junit4:junit4]   2> 305 T1953 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362759909847/'
[junit4:junit4]   2> 305 T1953 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362759909847/'
[junit4:junit4]   2> 322 T1953 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 323 T1953 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 323 T1953 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 323 T1953 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 324 T1953 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 324 T1953 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 324 T1953 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 325 T1953 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 325 T1953 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 325 T1953 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 331 T1953 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 340 T1953 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:42321/solr
[junit4:junit4]   2> 341 T1953 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 341 T1953 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42321 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@5884545c
[junit4:junit4]   2> 342 T1953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 342 T1972 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42321. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 343 T1972 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42321, initiating session
[junit4:junit4]   2> 343 T1955 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33497
[junit4:junit4]   2> 343 T1955 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33497
[junit4:junit4]   2> 344 T1957 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4ad200e90002 with negotiated timeout 20000 for client /127.0.0.1:33497
[junit4:junit4]   2> 344 T1972 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42321, sessionid = 0x13d4ad200e90002, negotiated timeout = 20000
[junit4:junit4]   2> 344 T1973 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5884545c name:ZooKeeperConnection Watcher:127.0.0.1:42321 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 345 T1953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 346 T1958 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4ad200e90002
[junit4:junit4]   2> 346 T1973 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 346 T1955 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33497 which had sessionid 0x13d4ad200e90002
[junit4:junit4]   2> 346 T1953 oaz.ZooKeeper.close Session: 0x13d4ad200e90002 closed
[junit4:junit4]   2> 347 T1953 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 350 T1953 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42321/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@5f83b020
[junit4:junit4]   2> 351 T1953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 351 T1974 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42321. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 352 T1974 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42321, initiating session
[junit4:junit4]   2> 352 T1955 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33498
[junit4:junit4]   2> 352 T1955 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33498
[junit4:junit4]   2> 353 T1957 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4ad200e90003 with negotiated timeout 20000 for client /127.0.0.1:33498
[junit4:junit4]   2> 353 T1974 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42321, sessionid = 0x13d4ad200e90003, negotiated timeout = 20000
[junit4:junit4]   2> 353 T1975 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5f83b020 name:ZooKeeperConnection Watcher:127.0.0.1:42321/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 354 T1953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 355 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 355 T1953 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 357 T1953 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53028_
[junit4:junit4]   2> 357 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:53028_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:53028_
[junit4:junit4]   2> 358 T1953 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53028_
[junit4:junit4]   2> 359 T1953 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 362 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90003 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> 362 T1953 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 365 T1953 oasc.Overseer.start Overseer (id=89309833436135427-127.0.0.1:53028_-n_0000000000) starting
[junit4:junit4]   2> 365 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 366 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 366 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 367 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 367 T1977 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 367 T1953 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 370 T1953 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4]   2> 371 T1953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 382 T1976 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 384 T1978 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362759909847/collection1
[junit4:junit4]   2> 384 T1978 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 384 T1978 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 384 T1978 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 385 T1978 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362759909847/collection1/'
[junit4:junit4]   2> 385 T1978 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362759909847/collection1/lib/README' to classloader
[junit4:junit4]   2> 386 T1978 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362759909847/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 407 T1978 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 439 T1978 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 440 T1978 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 443 T1978 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 784 T1978 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 789 T1978 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 791 T1978 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 800 T1978 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 809 T1978 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 812 T1978 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 813 T1978 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 813 T1978 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 813 T1978 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 814 T1978 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 814 T1978 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 814 T1978 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362759909847/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/control/data/
[junit4:junit4]   2> 814 T1978 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@644f224c
[junit4:junit4]   2> 815 T1978 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 815 T1978 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/control/data forceNew: false
[junit4:junit4]   2> 815 T1978 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/control/data/index/
[junit4:junit4]   2> 815 T1978 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 816 T1978 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/control/data/index forceNew: false
[junit4:junit4]   2> 817 T1978 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e2db297 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1f7154be),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 817 T1978 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 818 T1978 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 819 T1978 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 819 T1978 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 819 T1978 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 820 T1978 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 820 T1978 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 820 T1978 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 820 T1978 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 820 T1978 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 823 T1978 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 824 T1978 oass.SolrIndexSearcher.<init> Opening Searcher@1ad6cd10 main
[junit4:junit4]   2> 825 T1978 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/control/data/tlog
[junit4:junit4]   2> 825 T1978 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 825 T1978 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 827 T1979 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1ad6cd10 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 829 T1978 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 829 T1978 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 829 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90003 type:create cxid:0x55 zxid:0x2a txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4]   2> 1462 T448 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 1884 T1976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 1885 T1976 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53028",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53028_"}
[junit4:junit4]   2> 1885 T1976 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 1885 T1976 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 1885 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90003 type:create cxid:0x5d zxid:0x2d txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 1889 T1975 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> 2831 T1978 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 2831 T1978 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53028 collection:control_collection shard:shard1
[junit4:junit4]   2> 2832 T1978 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 2836 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90003 type:delete cxid:0x77 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 2837 T1978 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 2837 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90003 type:create cxid:0x78 zxid:0x38 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2838 T1978 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2839 T1978 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2839 T1978 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53028/collection1/
[junit4:junit4]   2> 2839 T1978 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 2839 T1978 oasc.SyncStrategy.syncToMe http://127.0.0.1:53028/collection1/ has no replicas
[junit4:junit4]   2> 2839 T1978 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53028/collection1/
[junit4:junit4]   2> 2839 T1978 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 2842 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90003 type:create cxid:0x82 zxid:0x3c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3214 T456 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 3391 T1976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3397 T1975 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> 3444 T1978 oasc.ZkController.register We are http://127.0.0.1:53028/collection1/ and leader is http://127.0.0.1:53028/collection1/
[junit4:junit4]   2> 3445 T1978 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53028
[junit4:junit4]   2> 3445 T1978 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 3445 T1978 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 3445 T1978 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 3446 T1978 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3447 T1953 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   2> 3447 T1953 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 3448 T1953 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 3451 T1953 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 3451 T1953 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42321/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@7a6a78b6
[junit4:junit4]   2> 3452 T1953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3452 T1981 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42321. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 3453 T1981 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42321, initiating session
[junit4:junit4]   2> 3453 T1955 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33501
[junit4:junit4]   2> 3453 T1955 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33501
[junit4:junit4]   2> 3454 T1957 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4ad200e90004 with negotiated timeout 10000 for client /127.0.0.1:33501
[junit4:junit4]   2> 3454 T1981 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42321, sessionid = 0x13d4ad200e90004, negotiated timeout = 10000
[junit4:junit4]   2> 3454 T1982 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a6a78b6 name:ZooKeeperConnection Watcher:127.0.0.1:42321/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3454 T1953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3455 T1953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3457 T1953 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 3527 T1953 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 3529 T1953 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:41589
[junit4:junit4]   2> 3530 T1953 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 3530 T1953 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3530 T1953 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362759913060
[junit4:junit4]   2> 3531 T1953 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362759913060/solr.xml
[junit4:junit4]   2> 3531 T1953 oasc.CoreContainer.<init> New CoreContainer 1081189345
[junit4:junit4]   2> 3531 T1953 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362759913060/'
[junit4:junit4]   2> 3532 T1953 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362759913060/'
[junit4:junit4]   2> 3551 T1953 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 3552 T1953 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 3552 T1953 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 3553 T1953 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 3553 T1953 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 3553 T1953 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 3553 T1953 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 3554 T1953 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 3554 T1953 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 3554 T1953 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 3560 T1953 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 3570 T1953 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:42321/solr
[junit4:junit4]   2> 3570 T1953 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 3571 T1953 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42321 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@30679dca
[junit4:junit4]   2> 3572 T1953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3572 T1992 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42321. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 3573 T1992 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42321, initiating session
[junit4:junit4]   2> 3573 T1955 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33503
[junit4:junit4]   2> 3573 T1955 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33503
[junit4:junit4]   2> 3574 T1957 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4ad200e90005 with negotiated timeout 20000 for client /127.0.0.1:33503
[junit4:junit4]   2> 3574 T1992 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42321, sessionid = 0x13d4ad200e90005, negotiated timeout = 20000
[junit4:junit4]   2> 3574 T1993 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@30679dca name:ZooKeeperConnection Watcher:127.0.0.1:42321 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3574 T1953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3576 T1958 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4ad200e90005
[junit4:junit4]   2> 3576 T1993 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 3576 T1955 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33503 which had sessionid 0x13d4ad200e90005
[junit4:junit4]   2> 3576 T1953 oaz.ZooKeeper.close Session: 0x13d4ad200e90005 closed
[junit4:junit4]   2> 3576 T1953 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 3579 T1953 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42321/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1685a223
[junit4:junit4]   2> 3580 T1953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3581 T1994 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42321. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 3581 T1994 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42321, initiating session
[junit4:junit4]   2> 3581 T1955 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33504
[junit4:junit4]   2> 3581 T1955 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33504
[junit4:junit4]   2> 3582 T1957 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4ad200e90006 with negotiated timeout 20000 for client /127.0.0.1:33504
[junit4:junit4]   2> 3582 T1994 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42321, sessionid = 0x13d4ad200e90006, negotiated timeout = 20000
[junit4:junit4]   2> 3582 T1995 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1685a223 name:ZooKeeperConnection Watcher:127.0.0.1:42321/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3582 T1953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3583 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90006 type:create cxid:0x1 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3583 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90006 type:create cxid:0x2 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3584 T1953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4586 T1953 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41589_
[junit4:junit4]   2> 4587 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90006 type:delete cxid:0xb zxid:0x4c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:41589_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:41589_
[junit4:junit4]   2> 4587 T1953 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:41589_
[junit4:junit4]   2> 4590 T1975 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 4590 T1982 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 4590 T1975 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> 4590 T1995 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 4596 T1996 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362759913060/collection1
[junit4:junit4]   2> 4596 T1996 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 4597 T1996 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 4597 T1996 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 4598 T1996 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362759913060/collection1/'
[junit4:junit4]   2> 4599 T1996 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362759913060/collection1/lib/README' to classloader
[junit4:junit4]   2> 4599 T1996 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362759913060/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 4631 T1996 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 4658 T1996 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 4659 T1996 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 4662 T1996 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 4903 T1976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4904 T1976 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53028",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53028_"}
[junit4:junit4]   2> 4906 T1995 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> 4906 T1975 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> 4906 T1982 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> 5022 T1996 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 5025 T464 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 5028 T1996 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 5030 T1996 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 5040 T1996 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5044 T1996 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5048 T1996 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5049 T1996 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 5050 T1996 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 5050 T1996 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5051 T1996 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 5051 T1996 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 5051 T1996 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362759913060/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty1/
[junit4:junit4]   2> 5052 T1996 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@644f224c
[junit4:junit4]   2> 5052 T1996 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 5053 T1996 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty1 forceNew: false
[junit4:junit4]   2> 5053 T1996 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty1/index/
[junit4:junit4]   2> 5054 T1996 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 5054 T1996 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty1/index forceNew: false
[junit4:junit4]   2> 5056 T1996 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3701ce86 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2cff03b9),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 5056 T1996 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 5058 T1996 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 5059 T1996 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 5059 T1996 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 5060 T1996 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 5060 T1996 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 5060 T1996 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 5061 T1996 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 5061 T1996 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 5062 T1996 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 5065 T1996 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 5068 T1996 oass.SolrIndexSearcher.<init> Opening Searcher@6cbcbe16 main
[junit4:junit4]   2> 5068 T1996 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty1/tlog
[junit4:junit4]   2> 5069 T1996 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 5069 T1996 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 5074 T1997 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6cbcbe16 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 5076 T1996 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 5076 T1996 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 6410 T1976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6410 T1976 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:41589",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:41589_"}
[junit4:junit4]   2> 6411 T1976 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4]   2> 6411 T1976 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4]   2> 6415 T1982 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> 6415 T1995 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> 6415 T1975 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> 6913 T479 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 7077 T1996 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 7078 T1996 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:41589 collection:collection1 shard:shard2
[junit4:junit4]   2> 7083 T1996 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 7087 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90006 type:delete cxid:0x48 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 7088 T1996 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 7088 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90006 type:create cxid:0x49 zxid:0x5d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7089 T1996 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 7089 T1996 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 7090 T1996 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:41589/collection1/
[junit4:junit4]   2> 7090 T1996 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 7090 T1996 oasc.SyncStrategy.syncToMe http://127.0.0.1:41589/collection1/ has no replicas
[junit4:junit4]   2> 7090 T1996 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:41589/collection1/
[junit4:junit4]   2> 7090 T1996 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 7093 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90006 type:create cxid:0x53 zxid:0x61 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7210 T496 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 7918 T1976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7923 T1975 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> 7923 T1995 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> 7923 T1982 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> 7946 T1996 oasc.ZkController.register We are http://127.0.0.1:41589/collection1/ and leader is http://127.0.0.1:41589/collection1/
[junit4:junit4]   2> 7946 T1996 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:41589
[junit4:junit4]   2> 7946 T1996 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 7946 T1996 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 7947 T1996 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 7948 T1996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7949 T1953 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   2> 7949 T1953 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 7949 T1953 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 8006 T1953 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 8008 T1953 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:60893
[junit4:junit4]   2> 8009 T1953 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 8009 T1953 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8009 T1953 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362759917555
[junit4:junit4]   2> 8010 T1953 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362759917555/solr.xml
[junit4:junit4]   2> 8010 T1953 oasc.CoreContainer.<init> New CoreContainer 631986257
[junit4:junit4]   2> 8010 T1953 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362759917555/'
[junit4:junit4]   2> 8011 T1953 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362759917555/'
[junit4:junit4]   2> 8027 T1953 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 8027 T1953 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 8028 T1953 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 8028 T1953 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 8028 T1953 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 8028 T1953 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 8029 T1953 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 8029 T1953 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 8029 T1953 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 8030 T1953 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 8035 T1953 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 8043 T1953 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:42321/solr
[junit4:junit4]   2> 8044 T1953 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 8044 T1953 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42321 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1b93fd02
[junit4:junit4]   2> 8045 T1953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8045 T2008 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42321. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 8046 T2008 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42321, initiating session
[junit4:junit4]   2> 8046 T1955 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33510
[junit4:junit4]   2> 8046 T1955 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33510
[junit4:junit4]   2> 8047 T1957 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4ad200e90007 with negotiated timeout 20000 for client /127.0.0.1:33510
[junit4:junit4]   2> 8047 T2008 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42321, sessionid = 0x13d4ad200e90007, negotiated timeout = 20000
[junit4:junit4]   2> 8047 T2009 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b93fd02 name:ZooKeeperConnection Watcher:127.0.0.1:42321 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8048 T1953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8048 T1958 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4ad200e90007
[junit4:junit4]   2> 8049 T1955 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33510 which had sessionid 0x13d4ad200e90007
[junit4:junit4]   2> 8049 T1953 oaz.ZooKeeper.close Session: 0x13d4ad200e90007 closed
[junit4:junit4]   2> 8049 T2009 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 8049 T1953 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 8052 T1953 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42321/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@7cd049e9
[junit4:junit4]   2> 8053 T1953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8053 T2010 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42321. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 8053 T2010 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42321, initiating session
[junit4:junit4]   2> 8053 T1955 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33511
[junit4:junit4]   2> 8054 T1955 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33511
[junit4:junit4]   2> 8054 T1957 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4ad200e90008 with negotiated timeout 20000 for client /127.0.0.1:33511
[junit4:junit4]   2> 8054 T2010 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42321, sessionid = 0x13d4ad200e90008, negotiated timeout = 20000
[junit4:junit4]   2> 8055 T2011 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7cd049e9 name:ZooKeeperConnection Watcher:127.0.0.1:42321/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8055 T1953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8055 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90008 type:create cxid:0x1 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8056 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90008 type:create cxid:0x2 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8057 T1953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 8929 T513 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 9059 T1953 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60893_
[junit4:junit4]   2> 9060 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90008 type:delete cxid:0xb zxid:0x70 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:60893_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:60893_
[junit4:junit4]   2> 9061 T1953 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60893_
[junit4:junit4]   2> 9062 T1982 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> 9062 T1975 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9062 T2011 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9063 T1975 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> 9063 T1995 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9063 T1995 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> 9064 T1982 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9067 T2012 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362759917555/collection1
[junit4:junit4]   2> 9067 T2012 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 9068 T2012 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 9068 T2012 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 9069 T2012 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362759917555/collection1/'
[junit4:junit4]   2> 9069 T2012 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362759917555/collection1/lib/README' to classloader
[junit4:junit4]   2> 9069 T2012 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362759917555/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 9101 T2012 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 9129 T2012 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 9130 T2012 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 9133 T2012 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 9427 T1976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9428 T1976 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:41589",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:41589_"}
[junit4:junit4]   2> 9430 T1995 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> 9430 T1982 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> 9430 T2011 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> 9430 T1975 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> 9450 T2012 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 9455 T2012 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 9457 T2012 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 9466 T2012 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 9468 T2012 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 9471 T2012 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 9472 T2012 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 9472 T2012 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 9472 T2012 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 9473 T2012 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 9473 T2012 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 9473 T2012 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362759917555/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty2/
[junit4:junit4]   2> 9473 T2012 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@644f224c
[junit4:junit4]   2> 9474 T2012 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 9474 T2012 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty2 forceNew: false
[junit4:junit4]   2> 9474 T2012 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty2/index/
[junit4:junit4]   2> 9475 T2012 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 9475 T2012 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty2/index forceNew: false
[junit4:junit4]   2> 9476 T2012 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@38bd6ca1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@453c5ba5),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9476 T2012 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 9478 T2012 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 9478 T2012 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 9478 T2012 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 9479 T2012 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 9479 T2012 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 9479 T2012 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 9480 T2012 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 9480 T2012 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 9480 T2012 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 9482 T2012 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 9484 T2012 oass.SolrIndexSearcher.<init> Opening Searcher@43759f4e main
[junit4:junit4]   2> 9485 T2012 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty2/tlog
[junit4:junit4]   2> 9485 T2012 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 9485 T2012 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 9489 T2013 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@43759f4e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 9491 T2012 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 9491 T2012 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 10934 T1976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10935 T1976 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:60893",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:60893_"}
[junit4:junit4]   2> 10935 T1976 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 10935 T1976 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 10938 T1982 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> 10938 T1995 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> 10938 T1975 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> 10938 T2011 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> 11493 T2012 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 11493 T2012 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:60893 collection:collection1 shard:shard1
[junit4:junit4]   2> 11494 T2012 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 11498 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90008 type:delete cxid:0x47 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard1 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard1
[junit4:junit4]   2> 11498 T2012 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 11499 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90008 type:create cxid:0x48 zxid:0x80 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 11500 T2012 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 11500 T2012 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 11500 T2012 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:60893/collection1/
[junit4:junit4]   2> 11500 T2012 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 11500 T2012 oasc.SyncStrategy.syncToMe http://127.0.0.1:60893/collection1/ has no replicas
[junit4:junit4]   2> 11501 T2012 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:60893/collection1/
[junit4:junit4]   2> 11501 T2012 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 11503 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90008 type:create cxid:0x51 zxid:0x83 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12441 T1976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12446 T1975 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> 12446 T1982 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> 12446 T1995 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> 12446 T2011 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> 12457 T2012 oasc.ZkController.register We are http://127.0.0.1:60893/collection1/ and leader is http://127.0.0.1:60893/collection1/
[junit4:junit4]   2> 12457 T2012 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60893
[junit4:junit4]   2> 12457 T2012 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 12457 T2012 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 12457 T2012 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 12459 T2012 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12460 T1953 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   2> 12460 T1953 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 12460 T1953 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 12517 T1953 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 12518 T1953 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:34074
[junit4:junit4]   2> 12519 T1953 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 12520 T1953 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 12520 T1953 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362759922066
[junit4:junit4]   2> 12521 T1953 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362759922066/solr.xml
[junit4:junit4]   2> 12521 T1953 oasc.CoreContainer.<init> New CoreContainer 1822256257
[junit4:junit4]   2> 12521 T1953 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362759922066/'
[junit4:junit4]   2> 12522 T1953 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362759922066/'
[junit4:junit4]   2> 12545 T1953 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 12545 T1953 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 12546 T1953 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 12546 T1953 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 12546 T1953 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 12546 T1953 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 12547 T1953 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 12547 T1953 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 12548 T1953 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 12548 T1953 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 12554 T1953 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 12564 T1953 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:42321/solr
[junit4:junit4]   2> 12564 T1953 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 12564 T1953 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42321 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@84bd86c
[junit4:junit4]   2> 12565 T1953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12565 T2024 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42321. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 12566 T2024 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42321, initiating session
[junit4:junit4]   2> 12566 T1955 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33518
[junit4:junit4]   2> 12567 T1955 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33518
[junit4:junit4]   2> 12567 T1957 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4ad200e90009 with negotiated timeout 20000 for client /127.0.0.1:33518
[junit4:junit4]   2> 12567 T2024 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42321, sessionid = 0x13d4ad200e90009, negotiated timeout = 20000
[junit4:junit4]   2> 12568 T2025 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@84bd86c name:ZooKeeperConnection Watcher:127.0.0.1:42321 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12568 T1953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12569 T1958 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4ad200e90009
[junit4:junit4]   2> 12569 T2025 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 12569 T1955 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33518 which had sessionid 0x13d4ad200e90009
[junit4:junit4]   2> 12569 T1953 oaz.ZooKeeper.close Session: 0x13d4ad200e90009 closed
[junit4:junit4]   2> 12569 T1953 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 12572 T1953 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42321/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@8c096c2
[junit4:junit4]   2> 12573 T1953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12573 T2026 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42321. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 12573 T2026 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42321, initiating session
[junit4:junit4]   2> 12573 T1955 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33519
[junit4:junit4]   2> 12574 T1955 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33519
[junit4:junit4]   2> 12574 T1957 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4ad200e9000a with negotiated timeout 20000 for client /127.0.0.1:33519
[junit4:junit4]   2> 12574 T2026 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42321, sessionid = 0x13d4ad200e9000a, negotiated timeout = 20000
[junit4:junit4]   2> 12575 T2027 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8c096c2 name:ZooKeeperConnection Watcher:127.0.0.1:42321/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12575 T1953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12575 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e9000a type:create cxid:0x1 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12576 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e9000a type:create cxid:0x2 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12577 T1953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 13579 T1953 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34074_
[junit4:junit4]   2> 13580 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e9000a type:delete cxid:0xb zxid:0x92 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:34074_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:34074_
[junit4:junit4]   2> 13581 T1953 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:34074_
[junit4:junit4]   2> 13583 T1995 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> 13583 T2011 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> 13584 T2027 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13584 T1975 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13584 T1982 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13584 T1975 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> 13584 T1982 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> 13585 T1995 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13585 T2011 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13588 T2028 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362759922066/collection1
[junit4:junit4]   2> 13588 T2028 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 13589 T2028 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 13589 T2028 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 13589 T2028 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362759922066/collection1/'
[junit4:junit4]   2> 13590 T2028 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362759922066/collection1/lib/README' to classloader
[junit4:junit4]   2> 13590 T2028 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362759922066/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 13611 T2028 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 13642 T2028 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 13642 T2028 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 13646 T2028 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 13947 T2028 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 13950 T1976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13950 T1976 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:60893",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:60893_"}
[junit4:junit4]   2> 13952 T2028 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 13952 T1975 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> 13952 T1982 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> 13952 T2027 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> 13953 T1995 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> 13953 T2011 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> 13954 T2028 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 13962 T2028 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 13965 T2028 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 13967 T2028 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 13968 T2028 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 13968 T2028 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 13968 T2028 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 13969 T2028 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 13969 T2028 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 13969 T2028 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362759922066/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty3/
[junit4:junit4]   2> 13969 T2028 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@644f224c
[junit4:junit4]   2> 13970 T2028 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 13970 T2028 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty3 forceNew: false
[junit4:junit4]   2> 13970 T2028 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty3/index/
[junit4:junit4]   2> 13970 T2028 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 13971 T2028 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty3/index forceNew: false
[junit4:junit4]   2> 13972 T2028 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@27c67b78 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d43a0c1),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 13972 T2028 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 13974 T2028 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 13974 T2028 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 13974 T2028 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 13975 T2028 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 13975 T2028 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 13975 T2028 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 13975 T2028 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 13976 T2028 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 13976 T2028 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 13978 T2028 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 13980 T2028 oass.SolrIndexSearcher.<init> Opening Searcher@75a630e2 main
[junit4:junit4]   2> 13980 T2028 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty3/tlog
[junit4:junit4]   2> 13980 T2028 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 13981 T2028 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 13984 T2029 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@75a630e2 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 13985 T2028 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 13986 T2028 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 15455 T1976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15456 T1976 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:34074",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:34074_"}
[junit4:junit4]   2> 15456 T1976 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 15456 T1976 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4]   2> 15460 T2027 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> 15460 T1975 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> 15460 T2011 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> 15460 T1995 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> 15460 T1982 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> 15987 T2028 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 15987 T2028 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:34074 collection:collection1 shard:shard2
[junit4:junit4]   2> 15989 T2028 oasc.ZkController.register We are http://127.0.0.1:34074/collection1/ and leader is http://127.0.0.1:41589/collection1/
[junit4:junit4]   2> 15990 T2028 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:34074
[junit4:junit4]   2> 15990 T2028 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 15990 T2028 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C66 name=collection1 org.apache.solr.core.SolrCore@4a0410cd url=http://127.0.0.1:34074/collection1 node=127.0.0.1:34074_ C66_STATE=coll:collection1 core:collection1 props:{collection=collection1, base_url=http://127.0.0.1:34074, core=collection1, state=down, node_name=127.0.0.1:34074_}
[junit4:junit4]   2> 15990 T2030 C66 P34074 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 15991 T2028 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15993 T2030 C66 P34074 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 15993 T1953 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   2> 15993 T2030 C66 P34074 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 15993 T1953 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 15993 T2030 C66 P34074 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 15993 T1953 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 15994 T2030 C66 P34074 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 15998 T1953 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15999 T1953 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 16007 T1988 oasc.CoreContainer.create Creating SolrCore 'onenodecollectioncore' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362759913060/onenodecollectioncore
[junit4:junit4]   2> 16008 T1988 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4]   2> 16009 T1988 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4]   2> 16009 T1988 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4]   2> 16010 T1988 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4]   2> 16011 T1988 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4]   2> 16012 T1988 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4]   2> 16013 T1988 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362759913060/onenodecollectioncore/'
[junit4:junit4]   2> 16052 T1988 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 16087 T1988 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 16087 T1988 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 16091 T1988 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 16532 T1988 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 16540 T1988 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 16544 T1988 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 16556 T1988 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 16560 T1988 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 16563 T1988 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 16564 T1988 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 16565 T1988 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 16565 T1988 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 16566 T1988 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 16566 T1988 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 16566 T1988 oasc.SolrCore.<init> [onenodecollectioncore] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362759913060/onenodecollectioncore/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1362759909607/onenodecollection/
[junit4:junit4]   2> 16567 T1988 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@644f224c
[junit4:junit4]   2> 16568 T1988 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 16569 T1988 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1362759909607/onenodecollection forceNew: false
[junit4:junit4]   2> 16569 T1988 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1362759909607/onenodecollection/index/
[junit4:junit4]   2> 16569 T1988 oasc.SolrCore.initIndex WARNING [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1362759909607/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 16570 T1988 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1362759909607/onenodecollection/index forceNew: false
[junit4:junit4]   2> 16571 T1988 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15f5fadf lockFactory=org.apache.lucene.store.NativeFSLockFactory@612963b3),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 16571 T1988 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 16573 T1988 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 16573 T1988 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 16574 T1988 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 16574 T1988 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 16575 T1988 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 16575 T1988 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 16575 T1988 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 16576 T1988 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 16576 T1988 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 16579 T1988 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 16582 T1988 oass.SolrIndexSearcher.<init> Opening Searcher@283d4f59 main
[junit4:junit4]   2> 16582 T1988 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1362759909607/onenodecollection/tlog
[junit4:junit4]   2> 16583 T1988 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 16583 T1988 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 16586 T2032 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@283d4f59 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 16588 T1988 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4]   2> 16966 T1976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16967 T1976 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:34074",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:34074_"}
[junit4:junit4]   2> 16969 T1976 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "collection":"onenodecollection",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:41589",
[junit4:junit4]   2> 	  "core":"onenodecollectioncore",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":"none",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:41589_"}
[junit4:junit4]   2> 16970 T1976 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4]   2> 16970 T1976 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 16973 T2011 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> 16973 T1975 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> 16973 T1995 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> 16973 T2027 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> 16973 T1982 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> 17003 T1990 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {checkLive=true&nodeName=127.0.0.1:34074_&version=2&coreNodeName=127.0.0.1:34074__collection1&core=collection1&action=PREPRECOVERY&onlyIfLeader=true&state=recovering&wt=javabin} status=0 QTime=1000 
[junit4:junit4]   2> 17544 T762 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 17589 T1988 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4]   2> 17590 T1988 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:41589 collection:onenodecollection shard:shard1
[junit4:junit4]   2> 17591 T1988 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4]   2> 17600 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90006 type:delete cxid:0xa1 zxid:0xad txntype:-1 reqpath:n/a Error Path:/solr/collections/onenodecollection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/onenodecollection/leaders
[junit4:junit4]   2> 17601 T1988 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 17602 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90006 type:create cxid:0xa2 zxid:0xae txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 17603 T1988 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 17604 T1988 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 17604 T1988 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:41589/onenodecollectioncore/
[junit4:junit4]   2> 17604 T1988 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 17605 T1988 oasc.SyncStrategy.syncToMe http://127.0.0.1:41589/onenodecollectioncore/ has no replicas
[junit4:junit4]   2> 17605 T1988 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:41589/onenodecollectioncore/
[junit4:junit4]   2> 17605 T1988 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4]   2> 17609 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90006 type:create cxid:0xac zxid:0xb2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 18478 T1976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18483 T1982 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> 18483 T1975 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> 18484 T1995 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> 18484 T2011 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> 18484 T2027 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> 18511 T1988 oasc.ZkController.register We are http://127.0.0.1:41589/onenodecollectioncore/ and leader is http://127.0.0.1:41589/onenodecollectioncore/
[junit4:junit4]   2> 18512 T1988 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:41589
[junit4:junit4]   2> 18512 T1988 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 18512 T1988 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4]   2> 18514 T1988 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18515 T1988 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {collection=onenodecollection&version=2&dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1362759909607/onenodecollection&roles=none&name=onenodecollectioncore&action=CREATE&numShards=1&wt=javabin} status=0 QTime=2508 
[junit4:junit4]   2> 18515 T1953 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4]   2> 18516 T1953 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C66_STATE=coll:collection1 core:collection1 props:{collection=collection1, base_url=http://127.0.0.1:34074, core=collection1, shard=shard2, state=recovering, node_name=127.0.0.1:34074_}
[junit4:junit4]   2> 19004 T2030 C66 P34074 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:41589/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 19004 T2030 C66 P34074 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:34074 START replicas=[http://127.0.0.1:41589/collection1/] nUpdates=100
[junit4:junit4]   2> 19004 T2030 C66 P34074 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 19005 T2030 C66 P34074 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 19005 T2030 C66 P34074 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 19005 T2030 C66 P34074 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 19005 T2030 C66 P34074 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 19005 T2030 C66 P34074 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:41589/collection1/. core=collection1
[junit4:junit4]   2> 19005 T2030 C66 P34074 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C67 name=collection1 org.apache.solr.core.SolrCore@5254830e url=http://127.0.0.1:41589/collection1 node=127.0.0.1:41589_ C67_STATE=coll:collection1 core:collection1 props:{collection=collection1, base_url=http://127.0.0.1:41589, core=collection1, shard=shard2, state=active, node_name=127.0.0.1:41589_, leader=true}
[junit4:junit4]   2> 19009 T1988 C67 P41589 REQ /get {getVersions=100&version=2&distrib=false&qt=/get&wt=javabin} status=0 QTime=1 
[junit4:junit4]   2> 19010 T1991 C67 P41589 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 19011 T1991 C67 P41589 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3701ce86 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2cff03b9),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 19011 T1991 C67 P41589 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 19012 T1991 C67 P41589 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3701ce86 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2cff03b9),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3701ce86 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2cff03b9),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 19012 T1991 C67 P41589 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 19013 T1991 C67 P41589 oass.SolrIndexSearcher.<init> Opening Searcher@5e8186c6 realtime
[junit4:junit4]   2> 19013 T1991 C67 P41589 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 19013 T1991 C67 P41589 /update {softCommit=false&openSearcher=false&commit=true&version=2&waitSearcher=true&commit_end_point=true&wt=javabin} {commit=} 0 4
[junit4:junit4]   2> 19014 T2030 C66 P34074 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 19014 T2030 C66 P34074 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 19016 T1988 C67 P41589 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 19016 T1988 C67 P41589 REQ /replication {version=2&qt=/replication&command=indexversion&wt=javabin} status=0 QTime=1 
[junit4:junit4]   2> 19017 T2030 C66 P34074 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 19017 T2030 C66 P34074 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 19017 T2030 C66 P34074 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 19019 T1989 C67 P41589 REQ /replication {generation=2&version=2&qt=/replication&command=filelist&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 19020 T2030 C66 P34074 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 19021 T2030 C66 P34074 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty3/index.20130308192528623 forceNew: false
[junit4:junit4]   2> 19021 T2030 C66 P34074 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@17744533 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1af06c2e) fullCopy=false
[junit4:junit4]   2> 19027 T1991 C67 P41589 REQ /replication {generation=2&checksum=true&file=segments_2&qt=/replication&command=filecontent&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 19028 T2030 C66 P34074 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 19030 T2030 C66 P34074 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 19030 T2030 C66 P34074 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 19031 T2030 C66 P34074 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@27c67b78 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d43a0c1),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@27c67b78 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d43a0c1),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 19031 T2030 C66 P34074 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 19031 T2030 C66 P34074 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 19031 T2030 C66 P34074 oass.SolrIndexSearcher.<init> Opening Searcher@47510234 main
[junit4:junit4]   2> 19032 T2029 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@47510234 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 19033 T2030 C66 P34074 oash.SnapPuller.fetchLatestIndex removing temporary index download directory files MockDirWrapper(org.apache.lucene.store.RAMDirectory@17744533 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1af06c2e)
[junit4:junit4]   2> 19033 T2030 C66 P34074 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 19033 T2030 C66 P34074 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 19033 T2030 C66 P34074 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 19033 T2030 C66 P34074 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 19034 T2030 C66 P34074 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 19518 T1953 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19988 T1976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19988 T1976 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "collection":"onenodecollection",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:41589",
[junit4:junit4]   2> 	  "core":"onenodecollectioncore",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":"none",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:41589_"}
[junit4:junit4]   2> 19991 T1976 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:34074",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:34074_"}
[junit4:junit4]   2> 19994 T2011 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> 19994 T1995 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> 19994 T2027 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> 19994 T1982 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> 19994 T1975 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> 20520 T1953 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20520 T1953 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4]   2> 20521 T1953 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 20533 T2007 oejs.Response.sendError WARNING Committed before 404 Can not find: /onenodecollectioncore/update
[junit4:junit4]   2> 20533 T1953 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:42321 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1b9767bc
[junit4:junit4]   2> 20534 T2007 oejs.ServletHandler.doHandle WARNING /onenodecollectioncore/update java.lang.IllegalStateException: Committed
[junit4:junit4]   2> 	at org.eclipse.jetty.server.Response.resetBuffer(Response.java:1136)
[junit4:junit4]   2> 	at org.eclipse.jetty.server.Response.sendError(Response.java:314)
[junit4:junit4]   2> 	at org.apache.solr.client.solrj.embedded.JettySolrRunner$Servlet404.service(JettySolrRunner.java:465)
[junit4:junit4]   2> 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:770)
[junit4:junit4]   2> 	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:669)
[junit4:junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1336)
[junit4:junit4]   2> 	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:379)
[junit4:junit4]   2> 	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:141)
[junit4:junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1307)
[junit4:junit4]   2> 	at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:135)
[junit4:junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1307)
[junit4:junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:453)
[junit4:junit4]   2> 	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229)
[junit4:junit4]   2> 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
[junit4:junit4]   2> 	at org.eclipse.jetty.server.handler.GzipHandler.handle(GzipHandler.java:275)
[junit4:junit4]   2> 	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1074)
[junit4:junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:382)
[junit4:junit4]   2> 	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)
[junit4:junit4]   2> 	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1006)
[junit4:junit4]   2> 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
[junit4:junit4]   2> 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
[junit4:junit4]   2> 	at org.eclipse.jetty.server.Server.handle(Server.java:365)
[junit4:junit4]   2> 	at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:485)
[junit4:junit4]   2> 	at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:937)
[junit4:junit4]   2> 	at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:998)
[junit4:junit4]   2> 	at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:948)
[junit4:junit4]   2> 	at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:240)
[junit4:junit4]   2> 	at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)
[junit4:junit4]   2> 	at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:628)
[junit4:junit4]   2> 	at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52)
[junit4:junit4]   2> 	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4:junit4]   2> 	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4:junit4]   2> 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 
[junit4:junit4]   2> 20534 T2035 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:42321. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 20534 T1953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 20535 T2035 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:42321, initiating session
[junit4:junit4]   2> 20535 T1955 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:33571
[junit4:junit4]   2> 20536 T1955 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:33571
[junit4:junit4]   2> 20536 T1957 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4ad200e9000b with negotiated timeout 10000 for client /127.0.0.1:33571
[junit4:junit4]   2> 20536 T2035 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:42321, sessionid = 0x13d4ad200e9000b, negotiated timeout = 10000
[junit4:junit4]   2> 20536 T2036 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b9767bc name:ZooKeeperConnection Watcher:127.0.0.1:42321 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 20537 T1953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 20565 T1958 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4ad200e9000b
[junit4:junit4]   2> 20565 T2036 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 20565 T1955 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33571 which had sessionid 0x13d4ad200e9000b
[junit4:junit4]   2> 20565 T1953 oaz.ZooKeeper.close Session: 0x13d4ad200e9000b closed
[junit4:junit4]   2> 20566 T1958 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4ad200e90004
[junit4:junit4]   2> 20566 T1982 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 20566 T1955 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33501 which had sessionid 0x13d4ad200e90004
[junit4:junit4]   2> 20566 T1953 oaz.ZooKeeper.close Session: 0x13d4ad200e90004 closed
[junit4:junit4]   2> 20568 T1953 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 53028
[junit4:junit4]   2> 20569 T1953 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=147752565
[junit4:junit4]   2> 21499 T1976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 21500 T1976 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:53028__collection1",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53028",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53028_"}
[junit4:junit4]   2> 21505 T1975 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> 21505 T2011 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> 21505 T1995 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> 21505 T2027 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> 22570 T1953 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 22571 T1953 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 22575 T1953 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@4acca1d7
[junit4:junit4]   2> 22580 T1953 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 22580 T1953 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 22581 T1953 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 22581 T1953 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 22582 T1953 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 22583 T1953 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/control/data
[junit4:junit4]   2> 22584 T1953 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/control/data
[junit4:junit4]   2> 22584 T1953 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/control/data/index
[junit4:junit4]   2> 22585 T1953 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/control/data/index
[junit4:junit4]   2> 22586 T1976 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89309833436135427-127.0.0.1:53028_-n_0000000000) am no longer a leader.
[junit4:junit4]   2> 22588 T1958 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4ad200e90003
[junit4:junit4]   2> 22589 T2011 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> 22589 T1955 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33498 which had sessionid 0x13d4ad200e90003
[junit4:junit4]   2> 22589 T1953 oaz.ZooKeeper.close Session: 0x13d4ad200e90003 closed
[junit4:junit4]   2> 22589 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90006 type:delete cxid:0xb9 zxid:0xce txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 22590 T2027 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 22590 T2027 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> 22590 T1995 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 22591 T2011 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 22593 T1995 oasc.Overseer.start Overseer (id=89309833436135430-127.0.0.1:41589_-n_0000000001) starting
[junit4:junit4]   2> 22593 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90006 type:create cxid:0xbe zxid:0xd0 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 22594 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90006 type:create cxid:0xbf zxid:0xd1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 22594 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90006 type:create cxid:0xc0 zxid:0xd2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 22595 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90006 type:create cxid:0xc1 zxid:0xd3 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 22595 T1995 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> 22595 T2038 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 22596 T1995 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 22597 T2037 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 22598 T2037 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22598 T2037 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53028",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53028_"}
[junit4:junit4]   2> 22602 T1995 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> 22602 T2027 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> 22602 T2011 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> 22612 T1953 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4]   2> 22664 T1953 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 41589
[junit4:junit4]   2> 22665 T1953 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1081189345
[junit4:junit4]   2> 23889 T1975 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 23889 T1975 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> 23889 T1975 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 23889 T1975 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 24104 T2037 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 24105 T2037 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4]   2> 	  "collection":"onenodecollection",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:41589__onenodecollectioncore",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:41589",
[junit4:junit4]   2> 	  "core":"onenodecollectioncore",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":"none",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:41589_"}
[junit4:junit4]   2> 24107 T2037 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:41589__collection1",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:41589",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:41589_"}
[junit4:junit4]   2> 24111 T2011 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> 24111 T1995 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> 24111 T2027 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> 25668 T1953 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 25669 T1953 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 25671 T1953 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4]   2> 25674 T1953 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@5254830e
[junit4:junit4]   2> 25679 T1953 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 25680 T1953 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 25680 T1953 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 25681 T1953 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 25683 T1953 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 25684 T1953 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty1
[junit4:junit4]   2> 25685 T1953 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty1
[junit4:junit4]   2> 25685 T1953 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty1/index
[junit4:junit4]   2> 25686 T1953 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty1/index
[junit4:junit4]   2> 25687 T1953 oasc.SolrCore.close [onenodecollectioncore]  CLOSING SolrCore org.apache.solr.core.SolrCore@1aefa0ae
[junit4:junit4]   2> 25695 T1953 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 25695 T1953 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 25696 T1953 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 25696 T1953 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 25697 T1953 oasc.SolrCore.closeSearcher [onenodecollectioncore] Closing main searcher on request.
[junit4:junit4]   2> 25698 T1953 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1362759909607/onenodecollection/index
[junit4:junit4]   2> 25699 T1953 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1362759909607/onenodecollection/index
[junit4:junit4]   2> 25700 T1953 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1362759909607/onenodecollection
[junit4:junit4]   2> 25701 T1953 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1362759909607/onenodecollection
[junit4:junit4]   2> 25702 T2037 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89309833436135430-127.0.0.1:41589_-n_0000000001) am no longer a leader.
[junit4:junit4]   2> 25703 T1958 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4ad200e90006
[junit4:junit4]   2> 25705 T1995 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> 25705 T1955 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33504 which had sessionid 0x13d4ad200e90006
[junit4:junit4]   2> 25705 T1995 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 25705 T1953 oaz.ZooKeeper.close Session: 0x13d4ad200e90006 closed
[junit4:junit4]   2> 25706 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90008 type:delete cxid:0x71 zxid:0xe4 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 25706 T1995 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 25706 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e9000a type:delete cxid:0x55 zxid:0xe5 txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard2 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard2
[junit4:junit4]   2> 25706 T1995 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 25707 T2011 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 25707 T2027 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 25708 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e9000a type:create cxid:0x56 zxid:0xe6 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 25710 T2027 oasc.ShardLeaderElectionContext.shouldIBeLeader Checking if I should try and be the leader.
[junit4:junit4]   2> 25710 T2027 oasc.ShardLeaderElectionContext.shouldIBeLeader My last published State was Active, it's okay to be the leader.
[junit4:junit4]   2> 25710 T2027 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 25710 T2027 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:34074/collection1/
[junit4:junit4]   2> 25711 T2011 oasc.Overseer.start Overseer (id=89309833436135432-127.0.0.1:60893_-n_0000000002) starting
[junit4:junit4]   2> 25711 T2027 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:34074 START replicas=[http://127.0.0.1:41589/collection1/] nUpdates=100
[junit4:junit4]   2> 25711 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90008 type:create cxid:0x76 zxid:0xe9 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 25711 T2027 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:34074 DONE.  We have no versions.  sync failed.
[junit4:junit4]   2> 25712 T2027 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4]   2> 25712 T2027 oasc.ShardLeaderElectionContext.runLeaderProcess We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4:junit4]   2> 25712 T2027 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:34074/collection1/
[junit4:junit4]   2> 25712 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90008 type:create cxid:0x77 zxid:0xea txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 25712 T2027 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 25713 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90008 type:create cxid:0x78 zxid:0xeb txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 25715 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e90008 type:create cxid:0x79 zxid:0xec txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 25717 T2040 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 25717 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e9000a type:create cxid:0x5e zxid:0xee txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 25718 T2027 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> 25718 T2040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 25719 T2040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:41589",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:41589_"}
[junit4:junit4]   2> 25719 T2027 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 25720 T2041 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 25722 T2040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "collection":"onenodecollection",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:41589",
[junit4:junit4]   2> 	  "core":"onenodecollectioncore",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":"none",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:41589_"}
[junit4:junit4]   2> 25733 T1953 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4]   2> 25734 T2027 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> 25738 T2011 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 25738 T2011 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> 25739 T2011 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> 25785 T1953 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 60893
[junit4:junit4]   2> 25785 T1953 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=631986257
[junit4:junit4]   2> 26772 T779 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 26786 T1953 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 26786 T1953 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 26790 T1953 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@25f7e460
[junit4:junit4]   2> 26792 T1953 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 26793 T1953 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 26793 T1953 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 26793 T1953 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 26794 T1953 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 26794 T1953 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty2
[junit4:junit4]   2> 26795 T1953 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty2
[junit4:junit4]   2> 26795 T1953 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty2/index
[junit4:junit4]   2> 26795 T1953 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty2/index
[junit4:junit4]   2> 26796 T2040 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89309833436135432-127.0.0.1:60893_-n_0000000002) am no longer a leader.
[junit4:junit4]   2> 26796 T1958 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4ad200e90008
[junit4:junit4]   2> 26797 T1955 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33511 which had sessionid 0x13d4ad200e90008
[junit4:junit4]   2> 26797 T1953 oaz.ZooKeeper.close Session: 0x13d4ad200e90008 closed
[junit4:junit4]   2> 26798 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e9000a type:delete cxid:0x66 zxid:0x100 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 26798 T2027 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 26800 T2027 oasc.Overseer.start Overseer (id=89309833436135434-127.0.0.1:34074_-n_0000000003) starting
[junit4:junit4]   2> 26800 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e9000a type:create cxid:0x6b zxid:0x102 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 26801 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e9000a type:create cxid:0x6c zxid:0x103 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 26802 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e9000a type:create cxid:0x6d zxid:0x104 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 26802 T1958 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4ad200e9000a type:create cxid:0x6e zxid:0x105 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 26803 T2043 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 26803 T2027 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4:junit4]   2> 26803 T2027 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 26803 T2042 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 26805 T2042 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 26805 T2042 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:60893__collection1",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:60893",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:60893_"}
[junit4:junit4]   2> 26807 T2042 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:60893",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:60893_"}
[junit4:junit4]   2> 26810 T2027 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> 26820 T1953 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4]   2> 26871 T1953 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 34074
[junit4:junit4]   2> 26871 T1953 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1822256257
[junit4:junit4]   2> 27872 T1953 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 27873 T1953 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 27876 T1953 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@4a0410cd
[junit4:junit4]   2> 27880 T1953 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 27880 T1953 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 27881 T1953 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 27881 T1953 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 27882 T1953 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 27882 T1953 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty3/index
[junit4:junit4]   2> 27883 T1953 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty3/index
[junit4:junit4]   2> 27883 T1953 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty3
[junit4:junit4]   2> 27883 T1953 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty3
[junit4:junit4]   2> 27883 T1953 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty3/index.20130308192528623
[junit4:junit4]   2> 27884 T1953 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1362759909606/jetty3/index.20130308192528623
[junit4:junit4]   2> 27885 T2042 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89309833436135434-127.0.0.1:34074_-n_0000000003) am no longer a leader.
[junit4:junit4]   2> 27885 T1958 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4ad200e9000a
[junit4:junit4]   2> 27886 T2027 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 27886 T1955 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:33519 which had sessionid 0x13d4ad200e9000a
[junit4:junit4]   2> 27886 T2027 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 27886 T1953 oaz.ZooKeeper.close Session: 0x13d4ad200e9000a closed
[junit4:junit4]   2> 27886 T2027 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 27886 T2027 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 27908 T1953 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4]   2> 27962 T1953 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4]   2> 27963 T1953 oazs.ZooKeeperServer.shutdown shutting down
[junit4:junit4]   2> 27963 T1953 oazs.SessionTrackerImpl.shutdown Shutting down
[junit4:junit4]   2> 27963 T1953 oazs.PrepRequestProcessor.shutdown Shutting down
[junit4:junit4]   2> 27963 T1958 oazs.PrepRequestProcessor.run PrepRequestProcessor exited loop!
[junit4:junit4]   2> 27963 T1953 oazs.SyncRequestProcessor.shutdown Shutting down
[junit4:junit4]   2> 27964 T1957 oazs.SyncRequestProcessor.run SyncRequestProcessor exited!
[junit4:junit4]   2> 27964 T1953 oazs.FinalRequestProcessor.shutdown shutdown of request processor complete
[junit4:junit4]   2> 27965 T1953 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42321 42321
[junit4:junit4]   2> 27966 T1955 oazs.NIOServerCnxnFactory.run NIOServerCnxn factory exited run method
[junit4:junit4]   2> 27967 T1953 oazs.ZooKeeperServer.shutdown shutting down
[junit4:junit4]   2> 27967 T1953 oazs.SessionTrackerImpl.shutdown Shutting down
[junit4:junit4]   2> 27967 T1953 oazs.PrepRequestProcessor.shutdown Shutting down
[junit4:junit4]   2> 27967 T1953 oazs.SyncRequestProcessor.shutdown Shutting down
[junit4:junit4]   2> 27968 T1953 oazs.FinalRequestProcessor.shutdown shutdown of request processor complete
[junit4:junit4]   1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4]   1> / (2)
[junit4:junit4]   1> DATA:
[junit4:junit4]   1>     
[junit4:junit4]   1>  /solr (7)
[junit4:junit4]   1>   /solr/aliases.json (0)
[junit4:junit4]   1>   /solr/live_nodes (4)
[junit4:junit4]   1>    /solr/live_nodes/127.0.0.1:53028_ (0)
[junit4:junit4]   1>    /solr/live_nodes/127.0.0.1:34074_ (0)
[junit4:junit4]   1>    /solr/live_nodes/127.0.0.1:60893_ (0)
[junit4:junit4]   1>    /solr/live_nodes/127.0.0.1:41589_ (0)
[junit4:junit4]   1>   /solr/collections (3)
[junit4:junit4]   1>    /solr/collections/onenodecollection (2)
[junit4:junit4]   1>    DATA:
[junit4:junit4]   1>        {
[junit4:junit4]   1>          "configName":"conf1",
[junit4:junit4]   1>          "router":"compositeId"}
[junit4:junit4]   1>     /solr/collections/onenodecollection/leaders (1)
[junit4:junit4]   1>      /solr/collections/onenodecollection/leaders/shard1 (0)
[junit4:junit4]   1>      DATA:
[junit4:junit4]   1>          {
[junit4:junit4]   1>            "base_url":"http://127.0.0.1:41589",
[junit4:junit4]   1>            "core":"onenodecollectioncore",
[junit4:junit4]   1>            "node_name":"127.0.0.1:41589_"}
[junit4:junit4]   1>     /solr/collections/onenodecollection/leader_elect (1)
[junit4:junit4]   1>      /solr/collections/onenodecollection/leader_elect/shard1 (1)
[junit4:junit4]   1>       /solr/collections/onenodecollection/leader_elect/shard1/election (1)
[junit4:junit4]   1>        /solr/collections/onenodecollection/leader_elect/shard1/election/89309833436135430-127.0.0.1:41589__onenodecollectioncore-n_0000000000 (0)
[junit4:junit4]   1>    /solr/collections/control_collection (3)
[junit4:junit4]   1>    DATA:
[junit4:junit4]   1>        {"configName":"conf1"}
[junit4:junit4]   1>     /solr/collections/control_collection/leaders (1)
[junit4:junit4]   1>      /solr/collections/control_collection/leaders/shard1 (0)
[junit4:junit4]   1>      DATA:
[junit4:junit4]   1>          {
[junit4:junit4]   1>            "base_url":"http://127.0.0.1:53028",
[junit4:junit4]   1>            "core":"collection1",
[junit4:junit4]   1>            "node_name":"127.0.0.1:53028_"}
[junit4:junit4]   1>     /solr/collections/control_collection/leader_elect (1)
[junit4:junit4]   1>      /solr/collections/control_collection/leader_elect/shard1 (1)
[junit4:junit4]   1>       /solr/collections/control_collection/leader_elect/shard1/election (1)
[junit4:junit4]   1>        /solr/collections/control_collection/leader_elect/shard1/election/89309833436135427-127.0.0.1:53028__collection1-n_0000000000 (0)
[junit4:junit4]   1>     /solr/collections/control_collection/shards (0)
[junit4:junit4]   1>    /solr/collections/collection1 (3)
[junit4:junit4]   1>    DATA:
[junit4:junit4]   1>        {"configName":"conf1"}
[junit4:junit4]   1>     /solr/collections/collection1/leaders (2)
[junit4:junit4]   1>      /solr/collections/collection1/leaders/shard1 (0)
[junit4:junit4]   1>      DATA:
[junit4:junit4]   1>          {
[junit4:junit4]   1>            "base_url":"http://127.0.0.1:60893",
[junit4:junit4]   1>            "core":"collection1",
[junit4:junit4]   1>            "node_name":"127.0.0.1:60893_"}
[junit4:junit4]   1>      /solr/collections/collection1/leaders/shard2 (0)
[junit4:junit4]   1>      DATA:
[junit4:junit4]   1>          {
[junit4:junit4]   1>            "base_url":"http://127.0.0.1:41589",
[junit4:junit4]   1>            "core":"collection1",
[junit4:junit4]   1>            "node_name":"127.0.0.1:41589_"}
[junit4:junit4]   1>     /solr/collections/collection1/leader_elect (2)
[junit4:junit4]   1>      /solr/collections/collection1/leader_elect/shard1 (1)
[junit4:junit4]   1>       /solr/collections/collection1/leader_elect/shard1/election (1)
[junit4:junit4]   1>        /solr/collections/collection1/leader_elect/shard1/election/89309833436135432-127.0.0.1:60893__collection1-n_0000000000 (0)
[junit4:junit4]   1>      /solr/collections/collection1/leader_elect/shard2 (1)
[junit4:junit4]   1>       /solr/collections/collection1/leader_elect/shard2/election (2)
[junit4:junit4]   1>        /solr/collections/collection1/leader_elect/shard2/election/89309833436135430-127.0.0.1:41589__collection1-n_0000000000 (0)
[junit4:junit4]   1>        /solr/collections/collection1/leader_elect/shard2/election/89309833436135434-127.0.0.1:34074__collection1-n_0000000001 (0)
[junit4:junit4]   1>     /solr/collections/collection1/shards (0)
[junit4:junit4]   1>   /solr/overseer_elect (2)
[junit4:junit4]   1>    /solr/overseer_elect/election (4)
[junit4:junit4]   1>     /solr/overseer_elect/election/89309833436135432-127.0.0.1:60893_-n_0000000002 (0)
[junit4:junit4]   1>     /solr/overseer_elect/election/89309833436135434-127.0.0.1:34074_-n_0000000003 (0)
[junit4:junit4]   1>     /solr/overseer_elect/election/89309833436135430-127.0.0.1:41589_-n_0000000001 (0)
[junit4:junit4]   1>     /solr/overseer_elect/election/89309833436135427-127.0.0.1:53028_-n_0000000000 (0)
[junit4:junit4]   1>    /solr/overseer_elect/leader (0)
[junit4:junit4]   1>    DATA:
[junit4:junit4]   1>        {"id":"89309833436135427-127.0.0.1:53028_-n_0000000000"}
[junit4:junit4]   1>   /solr/overseer (3)
[junit4:junit4]   1>   DATA:
[junit4:junit4]   1>       
[junit4:junit4]   1>    /solr/overseer/collection-queue-work (0)
[junit4:junit4]   1>    DATA:
[junit4:junit4]   1>        
[junit4:junit4]   1>    /solr/overseer/queue (0)
[junit4:junit4]   1>    DATA:
[junit4:junit4]   1>        
[junit4:junit4]   1>    /solr/overseer/queue-work (0)
[junit4:junit4]   1>    DATA:
[junit4:junit4]   1>        
[junit4:junit4]   1>   /solr/configs (1)
[junit4:junit4]   1>    /solr/configs/conf1 (9)
[junit4:junit4]   1>     /solr/configs/conf1/open-exchange-rates.json (0)
[junit4:junit4]   1>     DATA:
[junit4:junit4]   1>         {
[junit4:junit4]   1>           "disclaimer": "This data is not real, it was synthetically created to match currency.xml.  It is modeled after the data format available from openexchangerates.org.  See https://openexchangerates.org/documentation for details",
[junit4:junit4]   1>           "license": "http://www.apache.org/licenses/LICENSE-2.0",
[junit4:junit4]   1>           "timestamp": 1332070464,
[junit4:junit4]   1>         
[junit4:junit4]   1>         
[junit4:junit4]   1>           "IMPORTANT NOTE": "In order for tests to work, this data must be kept in sync with ./currency.xml",
[junit4:junit4]   1>         
[junit4:junit4]   1>         
[junit4:junit4]   1>           "base": "USD",
[junit4:junit4]   1>           "rates": {
[junit4:junit4]   1>             "USD": 1,
[junit4:junit4]   1>             "JPY": 81.29,
[junit4:junit4]   1>             "EUR": 2.5,
[junit4:junit4]   1>             "GBP": 0.5,
[junit4:junit4]   1>             "MXN": 2.0
[junit4:junit4]   1>           }
[junit4:junit4]   1>         }
[junit4:junit4]   1>         
[junit4:junit4]   1>     /solr/configs/conf1/mapping-ISOLatin1Accent.txt (0)
[junit4:junit4]   1>     DATA: ...supressed...
[junit4:junit4]   1>     /solr/configs/conf1/solrconfig.xml (0)
[junit4:junit4]   1>     DATA: ...supressed...
[junit4:junit4]   1>     /solr/configs/conf1/currency.xml (0)
[junit4:junit4]   1>     DATA: ...supressed...
[junit4:junit4]   1>     /solr/configs/conf1/protwords.txt (0)
[junit4:junit4]   1>     DATA: ...supressed...
[junit4:junit4]   1>     /solr/configs/conf1/stopwords.txt (0)
[junit4:junit4]   1>     DATA: ...supressed...
[junit4:junit4]   1>     /solr/configs/conf1/schema.xml (0)
[junit4:junit4]   1>     DATA: ...supressed...
[junit4:junit4]   1>     /solr/configs/conf1/old_synonyms.txt (0)
[junit4:junit4]   1>     DATA: ...supressed...
[junit4:junit4]   1>     /solr/configs/conf1/synonyms.txt (0)
[junit4:jun

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

<
[junit4:junit4]    > Throwable #1: java.lang.AssertionError: Still found shard
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([6A68881E2A336321:EB8E06065D6C031D]:0)
[junit4:junit4]    > 	at org.junit.Assert.fail(Assert.java:93)
[junit4:junit4]    > 	at org.apache.solr.cloud.UnloadDistributedZkTest.testUnloadShardAndCollection(UnloadDistributedZkTest.java:124)
[junit4:junit4]    > 	at org.apache.solr.cloud.UnloadDistributedZkTest.doTest(UnloadDistributedZkTest.java:77)
[junit4:junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4:junit4]    > 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4:junit4]    > 	at java.lang.reflect.Method.invoke(Method.java:487)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 135802 T2045 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> 135813 T2044 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4:junit4]   2> 136518 T2048 oazs.SessionTrackerImpl.run SessionTrackerImpl exited loop!
[junit4:junit4]   2> 136911 T2127 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 136912 T2127 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 136912 T2127 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 136912 T2127 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> NOTE: test params are: codec=Lucene42: {text=PostingsFormat(name=NestedPulsing), _version_=PostingsFormat(name=TestBloomFilteredLucene41Postings), a_t=PostingsFormat(name=Lucene41WithOrds), range_facet_l=PostingsFormat(name=Lucene41WithOrds), id=PostingsFormat(name=Asserting), multiDefault=PostingsFormat(name=Lucene41WithOrds), other_tl1=PostingsFormat(name=TestBloomFilteredLucene41Postings), timestamp=PostingsFormat(name=Lucene41WithOrds), range_facet_sl=PostingsFormat(name=Asserting), range_facet_si=PostingsFormat(name=Lucene41WithOrds), a_si=PostingsFormat(name=TestBloomFilteredLucene41Postings), intDefault=PostingsFormat(name=TestBloomFilteredLucene41Postings)}, docValues:{timestamp=DocValuesFormat(name=Asserting)}, sim=DefaultSimilarity, locale=lv, timezone=Africa/Khartoum
[junit4:junit4]   2> NOTE: Linux 3.2.0-38-generic amd64/Oracle Corporation 1.8.0-ea (64-bit)/cpus=8,threads=1,free=244587624,total=337670144
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestPluginEnable, ShowFileRequestHandlerTest, MinimalSchemaTest, TestXIncludeConfig, SearchHandlerTest, TestCharFilters, UUIDFieldTest, LegacyHTMLStripCharFilterTest, TestIBSimilarityFactory, ResourceLoaderTest, TestSolrIndexConfig, SyncSliceTest, AutoCommitTest, TestConfig, ZkCLITest, OverseerTest, BadComponentTest, SliceStateUpdateTest, SuggesterFSTTest, PreAnalyzedFieldTest, FieldMutatingUpdateProcessorTest, SliceStateTest, TestStressVersions, LoggingHandlerTest, JsonLoaderTest, TestPhraseSuggestions, BasicFunctionalityTest, RegexBoostProcessorTest, TestCopyFieldCollectionResource, OverseerCollectionProcessorTest, TestSolrQueryParser, TermsComponentTest, PeerSyncTest, TestRemoteStreaming, DocValuesTest, RecoveryZkTest, SchemaVersionSpecificBehaviorTest, SynonymTokenizerTest, ResponseLogComponentTest, ZkControllerTest, ShardRoutingTest, WordBreakSolrSpellCheckerTest, TestPHPSerializedResponseWriter, ReturnFieldsTest, SolrInfoMBeanTest, DirectUpdateHandlerOptimizeTest, TestFieldCollectionResource, DistributedQueryElevationComponentTest, TestRealTimeGet, AnalysisAfterCoreReloadTest, SOLR749Test, TestFastWriter, TestCoreContainer, TestFastLRUCache, SolrCoreTest, TestSolrDeletionPolicy1, TestGroupingSearch, TestValueSourceCache, DistributedTermsComponentTest, MoreLikeThisHandlerTest, QueryParsingTest, PluginInfoTest, TestTrie, TestRandomDVFaceting, CSVRequestHandlerTest, BasicDistributedZk2Test, UnloadDistributedZkTest]
[junit4:junit4] Completed on J0 in 137.09s, 1 test, 1 failure <<< FAILURES!

[...truncated 417 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:381: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:361: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:183: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:449: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1213: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:877: There were test failures: 269 suites, 1137 tests, 1 error, 1 failure, 13 ignored (7 assumptions)

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



Mime
View raw message