lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.8.0-ea-b82) - Build # 4847 - Still Failing!
Date Sun, 24 Mar 2013 09:31:09 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/4847/
Java: 32bit/jdk1.8.0-ea-b82 -server -XX:+UseParallelGC

1 tests failed.
FAILED:  org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch

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

Stack Trace:
org.apache.solr.common.SolrException: Server at http://127.0.0.1:34680/gn_sex/c/onenodecollectioncore returned non ok status:404, message:Can not find: /gn_sex/c/onenodecollectioncore/update
	at __randomizedtesting.SeedInfo.seed([414EDA31D46C28C1:C0A85429A33348FD]: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:197)
	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 9261 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 0 T1536 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /gn_sex/c
[junit4:junit4]   2> 3 T1536 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-1364117038171
[junit4:junit4]   2> 3 T1536 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 4 T1537 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 5 T1537 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 5 T1537 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4]   2> 5 T1537 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4]   2> 6 T1537 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 6 T1537 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-1364117038171/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4]   2> 104 T1536 oasc.ZkTestServer.run start zk server on port:43174
[junit4:junit4]   2> 104 T1536 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:43174 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@179f418
[junit4:junit4]   2> 105 T1536 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 105 T1542 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:43174. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 106 T1542 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:43174, initiating session
[junit4:junit4]   2> 106 T1538 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38631
[junit4:junit4]   2> 106 T1538 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38631
[junit4:junit4]   2> 107 T1540 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 168 T1540 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d9bb6245f0000 with negotiated timeout 10000 for client /127.0.0.1:38631
[junit4:junit4]   2> 168 T1542 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:43174, sessionid = 0x13d9bb6245f0000, negotiated timeout = 10000
[junit4:junit4]   2> 169 T1543 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@179f418 name:ZooKeeperConnection Watcher:127.0.0.1:43174 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 169 T1536 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 170 T1536 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 175 T1541 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d9bb6245f0000
[junit4:junit4]   2> 176 T1543 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 176 T1538 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:38631 which had sessionid 0x13d9bb6245f0000
[junit4:junit4]   2> 176 T1536 oaz.ZooKeeper.close Session: 0x13d9bb6245f0000 closed
[junit4:junit4]   2> 177 T1536 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:43174/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1be02c7
[junit4:junit4]   2> 178 T1544 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:43174. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 178 T1536 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 179 T1544 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:43174, initiating session
[junit4:junit4]   2> 179 T1538 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38632
[junit4:junit4]   2> 179 T1538 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38632
[junit4:junit4]   2> 181 T1540 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d9bb6245f0001 with negotiated timeout 10000 for client /127.0.0.1:38632
[junit4:junit4]   2> 181 T1544 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:43174, sessionid = 0x13d9bb6245f0001, negotiated timeout = 10000
[junit4:junit4]   2> 181 T1545 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1be02c7 name:ZooKeeperConnection Watcher:127.0.0.1:43174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 181 T1536 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 182 T1536 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 187 T1536 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 193 T1536 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 197 T1536 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 202 T1536 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> 202 T1536 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 210 T1536 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> 211 T1536 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 218 T1536 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> 218 T1536 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 223 T1536 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> 224 T1536 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 229 T1536 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> 230 T1536 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 236 T1536 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> 236 T1536 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 241 T1536 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> 242 T1536 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 248 T1536 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> 248 T1536 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 253 T1536 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> 254 T1536 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 260 T1541 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d9bb6245f0001
[junit4:junit4]   2> 261 T1545 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 261 T1538 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:38632 which had sessionid 0x13d9bb6245f0001
[junit4:junit4]   2> 261 T1536 oaz.ZooKeeper.close Session: 0x13d9bb6245f0001 closed
[junit4:junit4]   2> 334 T1536 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 337 T1536 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57200
[junit4:junit4]   2> 338 T1536 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 338 T1536 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 338 T1536 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-1364117038429
[junit4:junit4]   2> 339 T1536 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-1364117038429/solr.xml
[junit4:junit4]   2> 339 T1536 oasc.CoreContainer.<init> New CoreContainer 23034514
[junit4:junit4]   2> 339 T1536 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-1364117038429/'
[junit4:junit4]   2> 339 T1536 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-1364117038429/'
[junit4:junit4]   2> 353 T1536 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 354 T1536 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 354 T1536 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 354 T1536 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 355 T1536 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 355 T1536 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 355 T1536 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 355 T1536 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 356 T1536 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 356 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 361 T1536 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 368 T1536 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:43174/solr
[junit4:junit4]   2> 369 T1536 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 369 T1536 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:43174 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@ca5bce
[junit4:junit4]   2> 370 T1555 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:43174. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 370 T1536 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 370 T1555 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:43174, initiating session
[junit4:junit4]   2> 371 T1538 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38633
[junit4:junit4]   2> 371 T1538 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38633
[junit4:junit4]   2> 372 T1540 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d9bb6245f0002 with negotiated timeout 20000 for client /127.0.0.1:38633
[junit4:junit4]   2> 372 T1555 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:43174, sessionid = 0x13d9bb6245f0002, negotiated timeout = 20000
[junit4:junit4]   2> 373 T1556 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ca5bce name:ZooKeeperConnection Watcher:127.0.0.1:43174 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 373 T1536 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 375 T1541 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d9bb6245f0002
[junit4:junit4]   2> 376 T1556 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 376 T1538 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:38633 which had sessionid 0x13d9bb6245f0002
[junit4:junit4]   2> 376 T1536 oaz.ZooKeeper.close Session: 0x13d9bb6245f0002 closed
[junit4:junit4]   2> 376 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 378 T1536 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:43174/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@32fd0f
[junit4:junit4]   2> 379 T1557 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:43174. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 379 T1536 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 379 T1557 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:43174, initiating session
[junit4:junit4]   2> 379 T1538 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38634
[junit4:junit4]   2> 380 T1538 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38634
[junit4:junit4]   2> 381 T1540 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d9bb6245f0003 with negotiated timeout 20000 for client /127.0.0.1:38634
[junit4:junit4]   2> 381 T1557 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:43174, sessionid = 0x13d9bb6245f0003, negotiated timeout = 20000
[junit4:junit4]   2> 381 T1558 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32fd0f name:ZooKeeperConnection Watcher:127.0.0.1:43174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 382 T1536 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 383 T1536 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4]   2> 386 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0003 type:create cxid:0x7 zxid:0x1b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 388 T1536 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4]   2> 392 T1536 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 395 T1536 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57200_gn_sex%2Fc
[junit4:junit4]   2> 396 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0003 type:delete cxid:0x12 zxid:0x1e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:57200_gn_sex%2Fc Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:57200_gn_sex%2Fc
[junit4:junit4]   2> 397 T1536 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57200_gn_sex%2Fc
[junit4:junit4]   2> 402 T1536 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 411 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0003 type:delete cxid:0x20 zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 412 T1536 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 416 T1536 oasc.Overseer.start Overseer (id=89398774213836803-127.0.0.1:57200_gn_sex%2Fc-n_0000000000) starting
[junit4:junit4]   2> 417 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0003 type:create cxid:0x25 zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 419 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0003 type:create cxid:0x26 zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 421 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0003 type:create cxid:0x28 zxid:0x27 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 422 T1536 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4]   2> 427 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0003 type:create cxid:0x2e zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 429 T1560 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 430 T1536 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 435 T1536 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4]   2> 438 T1536 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 443 T1559 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 447 T1561 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-1364117038429/collection1
[junit4:junit4]   2> 447 T1561 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 448 T1561 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 448 T1561 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 450 T1561 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-1364117038429/collection1/'
[junit4:junit4]   2> 451 T1561 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-1364117038429/collection1/lib/README' to classloader
[junit4:junit4]   2> 451 T1561 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-1364117038429/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 487 T1561 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 511 T1561 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 512 T1561 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 515 T1561 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 542 T3 oasu.ConcurrentLRUCache.finalize SEVERE ConcurrentLRUCache was not destroyed prior to finalize(), indicates a bug -- POSSIBLE RESOURCE LEAK!!!
[junit4:junit4]   2> 788 T1561 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 793 T1561 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 795 T1561 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 813 T1561 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 816 T1561 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 820 T1561 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 822 T1561 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 822 T1561 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 823 T1561 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 824 T1561 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 825 T1561 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 825 T1561 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 825 T1561 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-1364117038429/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/control/data/
[junit4:junit4]   2> 826 T1561 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@164387c
[junit4:junit4]   2> 826 T1561 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 827 T1561 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/control/data
[junit4:junit4]   2> 827 T1561 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/control/data/index/
[junit4:junit4]   2> 828 T1561 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 828 T1561 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/control/data/index
[junit4:junit4]   2> 830 T1561 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@17d3376 lockFactory=org.apache.lucene.store.NativeFSLockFactory@d735af),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 831 T1561 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 833 T1561 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 833 T1561 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 834 T1561 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 835 T1561 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 835 T1561 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 836 T1561 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 836 T1561 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 837 T1561 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 837 T1561 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 841 T1561 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 845 T1561 oass.SolrIndexSearcher.<init> Opening Searcher@17243eb main
[junit4:junit4]   2> 845 T1561 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/control/data/tlog
[junit4:junit4]   2> 846 T1561 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 847 T1561 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 851 T1562 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@17243eb main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 852 T1561 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 852 T1561 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1950 T1559 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 1951 T1559 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> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:57200_gn_sex%2Fc",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:57200/gn_sex/c",
[junit4:junit4]   2> 	  "shard":null}
[junit4:junit4]   2> 1951 T1559 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 1951 T1559 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 1958 T1558 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> 2855 T1561 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 2855 T1561 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57200/gn_sex/c collection:control_collection shard:shard1
[junit4:junit4]   2> 2856 T1561 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 2868 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0003 type:delete cxid:0x82 zxid:0x35 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 2870 T1561 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 2870 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0003 type:create cxid:0x83 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2874 T1561 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2875 T1561 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2875 T1561 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57200/gn_sex/c/collection1/
[junit4:junit4]   2> 2875 T1561 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 2876 T1561 oasc.SyncStrategy.syncToMe http://127.0.0.1:57200/gn_sex/c/collection1/ has no replicas
[junit4:junit4]   2> 2876 T1561 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57200/gn_sex/c/collection1/
[junit4:junit4]   2> 2876 T1561 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 2883 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0003 type:create cxid:0x8e zxid:0x3a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3465 T1559 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3478 T1558 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> 3489 T1561 oasc.ZkController.register We are http://127.0.0.1:57200/gn_sex/c/collection1/ and leader is http://127.0.0.1:57200/gn_sex/c/collection1/
[junit4:junit4]   2> 3490 T1561 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57200/gn_sex/c
[junit4:junit4]   2> 3490 T1561 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 3490 T1561 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 3490 T1561 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 3493 T1561 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3495 T1536 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   2> 3496 T1536 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 3496 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 3500 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 3501 T1536 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:43174/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1492b3
[junit4:junit4]   2> 3502 T1536 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3502 T1564 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:43174. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 3502 T1564 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:43174, initiating session
[junit4:junit4]   2> 3502 T1538 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38635
[junit4:junit4]   2> 3503 T1538 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38635
[junit4:junit4]   2> 3504 T1540 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d9bb6245f0004 with negotiated timeout 10000 for client /127.0.0.1:38635
[junit4:junit4]   2> 3504 T1564 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:43174, sessionid = 0x13d9bb6245f0004, negotiated timeout = 10000
[junit4:junit4]   2> 3505 T1565 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1492b3 name:ZooKeeperConnection Watcher:127.0.0.1:43174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3505 T1536 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3507 T1536 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3510 T1536 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 3565 T1536 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 3568 T1536 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58596
[junit4:junit4]   2> 3569 T1536 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 3569 T1536 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3570 T1536 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-1364117041678
[junit4:junit4]   2> 3570 T1536 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-1364117041678/solr.xml
[junit4:junit4]   2> 3571 T1536 oasc.CoreContainer.<init> New CoreContainer 13040952
[junit4:junit4]   2> 3572 T1536 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-1364117041678/'
[junit4:junit4]   2> 3573 T1536 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-1364117041678/'
[junit4:junit4]   2> 3604 T1536 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 3604 T1536 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 3604 T1536 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 3605 T1536 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 3605 T1536 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 3605 T1536 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 3605 T1536 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 3606 T1536 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 3606 T1536 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 3606 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 3611 T1536 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 3619 T1536 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:43174/solr
[junit4:junit4]   2> 3619 T1536 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 3619 T1536 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:43174 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@15db187
[junit4:junit4]   2> 3620 T1575 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:43174. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 3620 T1536 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3621 T1575 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:43174, initiating session
[junit4:junit4]   2> 3621 T1538 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38636
[junit4:junit4]   2> 3621 T1538 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38636
[junit4:junit4]   2> 3622 T1540 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d9bb6245f0005 with negotiated timeout 20000 for client /127.0.0.1:38636
[junit4:junit4]   2> 3622 T1575 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:43174, sessionid = 0x13d9bb6245f0005, negotiated timeout = 20000
[junit4:junit4]   2> 3623 T1576 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15db187 name:ZooKeeperConnection Watcher:127.0.0.1:43174 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3623 T1536 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3624 T1541 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d9bb6245f0005
[junit4:junit4]   2> 3625 T1538 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:38636 which had sessionid 0x13d9bb6245f0005
[junit4:junit4]   2> 3625 T1576 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 3625 T1536 oaz.ZooKeeper.close Session: 0x13d9bb6245f0005 closed
[junit4:junit4]   2> 3626 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 3631 T1536 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:43174/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@18217cc
[junit4:junit4]   2> 3632 T1577 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:43174. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 3632 T1536 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3633 T1577 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:43174, initiating session
[junit4:junit4]   2> 3633 T1538 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38637
[junit4:junit4]   2> 3633 T1538 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38637
[junit4:junit4]   2> 3634 T1540 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d9bb6245f0006 with negotiated timeout 20000 for client /127.0.0.1:38637
[junit4:junit4]   2> 3634 T1577 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:43174, sessionid = 0x13d9bb6245f0006, negotiated timeout = 20000
[junit4:junit4]   2> 3634 T1578 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18217cc name:ZooKeeperConnection Watcher:127.0.0.1:43174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3635 T1536 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3636 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0006 type:create cxid:0x1 zxid:0x48 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3638 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0006 type:create cxid:0x3 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3641 T1536 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4646 T1536 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58596_gn_sex%2Fc
[junit4:junit4]   2> 4648 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0006 type:delete cxid:0xd zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:58596_gn_sex%2Fc Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:58596_gn_sex%2Fc
[junit4:junit4]   2> 4649 T1536 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58596_gn_sex%2Fc
[junit4:junit4]   2> 4653 T1558 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> 4655 T1565 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 4655 T1578 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 4657 T1558 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 4665 T1579 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-1364117041678/collection1
[junit4:junit4]   2> 4665 T1579 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 4666 T1579 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 4667 T1579 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 4669 T1579 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-1364117041678/collection1/'
[junit4:junit4]   2> 4670 T1579 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-1364117041678/collection1/lib/README' to classloader
[junit4:junit4]   2> 4670 T1579 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-1364117041678/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 4704 T1579 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 4728 T1579 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 4729 T1579 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 4732 T1579 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 4986 T1559 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4987 T1559 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:57200_gn_sex%2Fc_collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:57200_gn_sex%2Fc",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:57200/gn_sex/c",
[junit4:junit4]   2> 	  "shard":"shard1"}
[junit4:junit4]   2> 4991 T1578 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> 4991 T1565 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> 4991 T1558 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> 5008 T1579 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 5013 T1579 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 5015 T1579 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 5028 T1579 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5031 T1579 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5033 T1579 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5034 T1579 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 5034 T1579 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 5034 T1579 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5035 T1579 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 5035 T1579 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 5036 T1579 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 5036 T1579 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-1364117041678/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty1/
[junit4:junit4]   2> 5036 T1579 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@164387c
[junit4:junit4]   2> 5036 T1579 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 5037 T1579 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty1
[junit4:junit4]   2> 5037 T1579 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty1/index/
[junit4:junit4]   2> 5037 T1579 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 5037 T1579 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty1/index
[junit4:junit4]   2> 5038 T1579 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1b2ec70 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a741f3),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 5038 T1579 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 5040 T1579 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 5040 T1579 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 5040 T1579 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 5041 T1579 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 5041 T1579 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 5041 T1579 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 5041 T1579 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 5042 T1579 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 5042 T1579 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 5044 T1579 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 5046 T1579 oass.SolrIndexSearcher.<init> Opening Searcher@1c9aec3 main
[junit4:junit4]   2> 5046 T1579 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty1/tlog
[junit4:junit4]   2> 5046 T1579 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 5047 T1579 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 5050 T1580 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1c9aec3 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 5051 T1579 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 5051 T1579 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 6495 T1559 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6495 T1559 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:58596_gn_sex%2Fc",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:58596/gn_sex/c",
[junit4:junit4]   2> 	  "shard":null}
[junit4:junit4]   2> 6495 T1559 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4]   2> 6496 T1559 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 6522 T1578 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> 6522 T1565 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> 6522 T1558 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> 7052 T1579 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 7053 T1579 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58596/gn_sex/c collection:collection1 shard:shard1
[junit4:junit4]   2> 7054 T1579 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 7060 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0006 type:delete cxid:0x4a zxid:0x5a txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 7060 T1579 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 7061 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0006 type:create cxid:0x4b zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7063 T1579 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 7063 T1579 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 7064 T1579 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58596/gn_sex/c/collection1/
[junit4:junit4]   2> 7064 T1579 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 7064 T1579 oasc.SyncStrategy.syncToMe http://127.0.0.1:58596/gn_sex/c/collection1/ has no replicas
[junit4:junit4]   2> 7064 T1579 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58596/gn_sex/c/collection1/
[junit4:junit4]   2> 7064 T1579 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 7067 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0006 type:create cxid:0x56 zxid:0x5f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8028 T1559 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8088 T1558 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> 8088 T1565 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> 8088 T1578 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> 8121 T1579 oasc.ZkController.register We are http://127.0.0.1:58596/gn_sex/c/collection1/ and leader is http://127.0.0.1:58596/gn_sex/c/collection1/
[junit4:junit4]   2> 8121 T1579 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58596/gn_sex/c
[junit4:junit4]   2> 8122 T1579 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 8122 T1579 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 8122 T1579 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 8126 T1579 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8128 T1536 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   2> 8128 T1536 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 8129 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 8187 T1536 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 8189 T1536 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:34680
[junit4:junit4]   2> 8190 T1536 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 8190 T1536 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8190 T1536 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-1364117046303
[junit4:junit4]   2> 8190 T1536 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-1364117046303/solr.xml
[junit4:junit4]   2> 8191 T1536 oasc.CoreContainer.<init> New CoreContainer 14841682
[junit4:junit4]   2> 8191 T1536 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-1364117046303/'
[junit4:junit4]   2> 8191 T1536 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-1364117046303/'
[junit4:junit4]   2> 8206 T1536 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 8206 T1536 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 8206 T1536 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 8207 T1536 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 8207 T1536 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 8207 T1536 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 8207 T1536 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 8208 T1536 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 8208 T1536 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 8208 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 8213 T1536 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 8221 T1536 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:43174/solr
[junit4:junit4]   2> 8221 T1536 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 8222 T1536 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:43174 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@10163f3
[junit4:junit4]   2> 8223 T1591 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:43174. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 8222 T1536 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8223 T1591 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:43174, initiating session
[junit4:junit4]   2> 8223 T1538 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38659
[junit4:junit4]   2> 8224 T1538 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38659
[junit4:junit4]   2> 8225 T1540 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d9bb6245f0007 with negotiated timeout 20000 for client /127.0.0.1:38659
[junit4:junit4]   2> 8225 T1591 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:43174, sessionid = 0x13d9bb6245f0007, negotiated timeout = 20000
[junit4:junit4]   2> 8225 T1592 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10163f3 name:ZooKeeperConnection Watcher:127.0.0.1:43174 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8226 T1536 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8227 T1541 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d9bb6245f0007
[junit4:junit4]   2> 8228 T1592 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 8228 T1538 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:38659 which had sessionid 0x13d9bb6245f0007
[junit4:junit4]   2> 8228 T1536 oaz.ZooKeeper.close Session: 0x13d9bb6245f0007 closed
[junit4:junit4]   2> 8229 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 8234 T1536 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:43174/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@5a47a5
[junit4:junit4]   2> 8235 T1536 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8235 T1593 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:43174. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 8236 T1593 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:43174, initiating session
[junit4:junit4]   2> 8236 T1538 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38660
[junit4:junit4]   2> 8237 T1538 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38660
[junit4:junit4]   2> 8238 T1540 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d9bb6245f0008 with negotiated timeout 20000 for client /127.0.0.1:38660
[junit4:junit4]   2> 8238 T1593 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:43174, sessionid = 0x13d9bb6245f0008, negotiated timeout = 20000
[junit4:junit4]   2> 8239 T1594 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5a47a5 name:ZooKeeperConnection Watcher:127.0.0.1:43174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8239 T1536 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8240 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0008 type:create cxid:0x1 zxid:0x6c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8242 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0008 type:create cxid:0x3 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8247 T1536 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9252 T1536 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34680_gn_sex%2Fc
[junit4:junit4]   2> 9254 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0008 type:delete cxid:0xd zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:34680_gn_sex%2Fc Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:34680_gn_sex%2Fc
[junit4:junit4]   2> 9255 T1536 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:34680_gn_sex%2Fc
[junit4:junit4]   2> 9259 T1558 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> 9260 T1565 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9260 T1594 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9260 T1565 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> 9260 T1578 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9261 T1578 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> 9262 T1558 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9270 T1595 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-1364117046303/collection1
[junit4:junit4]   2> 9270 T1595 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 9271 T1595 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 9271 T1595 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 9274 T1595 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-1364117046303/collection1/'
[junit4:junit4]   2> 9274 T1595 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-1364117046303/collection1/lib/README' to classloader
[junit4:junit4]   2> 9275 T1595 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-1364117046303/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 9307 T1595 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 9343 T1595 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 9344 T1595 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 9347 T1595 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 9597 T1559 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9597 T1559 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:58596_gn_sex%2Fc_collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:58596_gn_sex%2Fc",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:58596/gn_sex/c",
[junit4:junit4]   2> 	  "shard":"shard1"}
[junit4:junit4]   2> 9601 T1558 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> 9601 T1594 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> 9601 T1565 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> 9601 T1578 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> 9622 T1595 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 9627 T1595 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 9629 T1595 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 9643 T1595 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 9645 T1595 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 9648 T1595 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 9649 T1595 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 9649 T1595 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 9650 T1595 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 9651 T1595 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 9651 T1595 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 9651 T1595 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 9651 T1595 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-1364117046303/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty2/
[junit4:junit4]   2> 9651 T1595 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@164387c
[junit4:junit4]   2> 9652 T1595 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 9652 T1595 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty2
[junit4:junit4]   2> 9652 T1595 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty2/index/
[junit4:junit4]   2> 9652 T1595 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 9653 T1595 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty2/index
[junit4:junit4]   2> 9654 T1595 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e5a9f lockFactory=org.apache.lucene.store.NativeFSLockFactory@6780f5),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9654 T1595 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 9655 T1595 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 9656 T1595 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 9656 T1595 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 9656 T1595 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 9657 T1595 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 9657 T1595 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 9657 T1595 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 9657 T1595 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 9658 T1595 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 9660 T1595 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 9661 T1595 oass.SolrIndexSearcher.<init> Opening Searcher@1547e91 main
[junit4:junit4]   2> 9662 T1595 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty2/tlog
[junit4:junit4]   2> 9662 T1595 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 9662 T1595 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 9665 T1596 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1547e91 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 9666 T1595 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 9666 T1595 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 11104 T1559 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11105 T1559 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:34680_gn_sex%2Fc",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:34680/gn_sex/c",
[junit4:junit4]   2> 	  "shard":null}
[junit4:junit4]   2> 11105 T1559 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 11106 T1559 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4]   2> 11108 T1558 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> 11108 T1565 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> 11108 T1578 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> 11108 T1594 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> 11669 T1595 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 11669 T1595 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:34680/gn_sex/c collection:collection1 shard:shard2
[junit4:junit4]   2> 11670 T1595 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 11676 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0008 type:delete cxid:0x49 zxid:0x7d txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard2 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard2
[junit4:junit4]   2> 11676 T1595 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 11676 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0008 type:create cxid:0x4a zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 11679 T1595 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 11679 T1595 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 11679 T1595 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:34680/gn_sex/c/collection1/
[junit4:junit4]   2> 11679 T1595 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 11679 T1595 oasc.SyncStrategy.syncToMe http://127.0.0.1:34680/gn_sex/c/collection1/ has no replicas
[junit4:junit4]   2> 11679 T1595 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:34680/gn_sex/c/collection1/
[junit4:junit4]   2> 11679 T1595 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 11683 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0008 type:create cxid:0x54 zxid:0x81 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12613 T1559 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12629 T1594 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> 12629 T1578 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> 12629 T1565 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> 12629 T1558 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> 12638 T1595 oasc.ZkController.register We are http://127.0.0.1:34680/gn_sex/c/collection1/ and leader is http://127.0.0.1:34680/gn_sex/c/collection1/
[junit4:junit4]   2> 12638 T1595 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:34680/gn_sex/c
[junit4:junit4]   2> 12639 T1595 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 12639 T1595 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 12639 T1595 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 12642 T1595 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12643 T1536 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   2> 12644 T1536 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 12645 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 12705 T1536 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 12707 T1536 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:39659
[junit4:junit4]   2> 12708 T1536 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 12709 T1536 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 12709 T1536 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-1364117050818
[junit4:junit4]   2> 12710 T1536 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-1364117050818/solr.xml
[junit4:junit4]   2> 12710 T1536 oasc.CoreContainer.<init> New CoreContainer 23984717
[junit4:junit4]   2> 12711 T1536 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-1364117050818/'
[junit4:junit4]   2> 12712 T1536 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-1364117050818/'
[junit4:junit4]   2> 12733 T1536 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 12733 T1536 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 12733 T1536 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 12734 T1536 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 12734 T1536 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 12734 T1536 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 12734 T1536 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 12735 T1536 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 12735 T1536 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 12735 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 12740 T1536 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 12748 T1536 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:43174/solr
[junit4:junit4]   2> 12749 T1536 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 12749 T1536 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:43174 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@ae2ad8
[junit4:junit4]   2> 12750 T1607 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:43174. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 12750 T1536 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12750 T1607 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:43174, initiating session
[junit4:junit4]   2> 12750 T1538 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38669
[junit4:junit4]   2> 12750 T1538 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38669
[junit4:junit4]   2> 12751 T1540 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d9bb6245f0009 with negotiated timeout 20000 for client /127.0.0.1:38669
[junit4:junit4]   2> 12752 T1607 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:43174, sessionid = 0x13d9bb6245f0009, negotiated timeout = 20000
[junit4:junit4]   2> 12752 T1608 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ae2ad8 name:ZooKeeperConnection Watcher:127.0.0.1:43174 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12752 T1536 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12754 T1541 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d9bb6245f0009
[junit4:junit4]   2> 12755 T1608 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 12755 T1538 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:38669 which had sessionid 0x13d9bb6245f0009
[junit4:junit4]   2> 12755 T1536 oaz.ZooKeeper.close Session: 0x13d9bb6245f0009 closed
[junit4:junit4]   2> 12755 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 12760 T1536 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:43174/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@14e1177
[junit4:junit4]   2> 12761 T1609 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:43174. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 12761 T1536 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12762 T1609 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:43174, initiating session
[junit4:junit4]   2> 12762 T1538 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38670
[junit4:junit4]   2> 12762 T1538 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38670
[junit4:junit4]   2> 12764 T1540 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d9bb6245f000a with negotiated timeout 20000 for client /127.0.0.1:38670
[junit4:junit4]   2> 12764 T1609 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:43174, sessionid = 0x13d9bb6245f000a, negotiated timeout = 20000
[junit4:junit4]   2> 12764 T1610 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14e1177 name:ZooKeeperConnection Watcher:127.0.0.1:43174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12764 T1536 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12766 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f000a type:create cxid:0x1 zxid:0x8e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12768 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f000a type:create cxid:0x3 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12772 T1536 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 13777 T1536 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39659_gn_sex%2Fc
[junit4:junit4]   2> 13778 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f000a type:delete cxid:0xd zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:39659_gn_sex%2Fc Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:39659_gn_sex%2Fc
[junit4:junit4]   2> 13779 T1536 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39659_gn_sex%2Fc
[junit4:junit4]   2> 13784 T1558 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> 13784 T1565 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> 13785 T1610 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13785 T1578 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13785 T1594 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13786 T1578 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> 13786 T1594 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> 13788 T1558 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13788 T1565 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13794 T1611 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-1364117050818/collection1
[junit4:junit4]   2> 13795 T1611 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 13796 T1611 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 13796 T1611 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 13799 T1611 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-1364117050818/collection1/'
[junit4:junit4]   2> 13799 T1611 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-1364117050818/collection1/lib/README' to classloader
[junit4:junit4]   2> 13800 T1611 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-1364117050818/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 13829 T1611 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 13853 T1611 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 13854 T1611 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 13857 T1611 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 14121 T1611 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 14126 T1611 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 14128 T1611 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 14138 T1559 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14139 T1559 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:34680_gn_sex%2Fc_collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:34680_gn_sex%2Fc",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:34680/gn_sex/c",
[junit4:junit4]   2> 	  "shard":"shard2"}
[junit4:junit4]   2> 14146 T1594 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> 14146 T1565 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> 14146 T1558 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> 14146 T1578 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> 14146 T1610 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> 14151 T1611 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14156 T1611 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14162 T1611 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14164 T1611 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 14164 T1611 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 14165 T1611 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14167 T1611 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 14167 T1611 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 14167 T1611 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 14168 T1611 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-1364117050818/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty3/
[junit4:junit4]   2> 14168 T1611 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@164387c
[junit4:junit4]   2> 14169 T1611 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 14169 T1611 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty3
[junit4:junit4]   2> 14170 T1611 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty3/index/
[junit4:junit4]   2> 14170 T1611 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 14171 T1611 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty3/index
[junit4:junit4]   2> 14173 T1611 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@185c20f lockFactory=org.apache.lucene.store.NativeFSLockFactory@8c480e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 14173 T1611 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 14176 T1611 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 14176 T1611 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 14177 T1611 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 14178 T1611 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 14178 T1611 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 14179 T1611 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 14179 T1611 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 14180 T1611 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 14180 T1611 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 14183 T1611 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 14187 T1611 oass.SolrIndexSearcher.<init> Opening Searcher@1afd89b main
[junit4:junit4]   2> 14187 T1611 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty3/tlog
[junit4:junit4]   2> 14188 T1611 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 14188 T1611 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 14193 T1612 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1afd89b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 14195 T1611 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 14195 T1611 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 15654 T1559 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15656 T1559 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:39659_gn_sex%2Fc",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:39659/gn_sex/c",
[junit4:junit4]   2> 	  "shard":null}
[junit4:junit4]   2> 15656 T1559 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 15656 T1559 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 15665 T1594 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> 15665 T1558 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> 15665 T1610 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> 15665 T1565 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> 15665 T1578 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> 16198 T1611 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 16198 T1611 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:39659/gn_sex/c collection:collection1 shard:shard1
[junit4:junit4]   2> 16204 T1611 oasc.ZkController.register We are http://127.0.0.1:39659/gn_sex/c/collection1/ and leader is http://127.0.0.1:58596/gn_sex/c/collection1/
[junit4:junit4]   2> 16204 T1611 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39659/gn_sex/c
[junit4:junit4]   2> 16204 T1611 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 16205 T1611 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C99 name=collection1 org.apache.solr.core.SolrCore@18511a9 url=http://127.0.0.1:39659/gn_sex/c/collection1 node=127.0.0.1:39659_gn_sex%2Fc C99_STATE=coll:collection1 core:collection1 props:{collection=collection1, state=down, node_name=127.0.0.1:39659_gn_sex%2Fc, core=collection1, base_url=http://127.0.0.1:39659/gn_sex/c}
[junit4:junit4]   2> 16205 T1613 C99 P39659 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 16206 T1611 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16207 T1613 C99 P39659 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 16207 T1613 C99 P39659 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 16208 T1613 C99 P39659 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 16208 T1536 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   2> 16209 T1613 C99 P39659 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 16209 T1536 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 16210 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 16268 T1536 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 16270 T1536 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36167
[junit4:junit4]   2> 16270 T1536 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 16271 T1536 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 16271 T1536 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-jetty4-1364117054382
[junit4:junit4]   2> 16271 T1536 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-jetty4-1364117054382/solr.xml
[junit4:junit4]   2> 16272 T1536 oasc.CoreContainer.<init> New CoreContainer 29420076
[junit4:junit4]   2> 16272 T1536 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-jetty4-1364117054382/'
[junit4:junit4]   2> 16272 T1536 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-jetty4-1364117054382/'
[junit4:junit4]   2> 16287 T1536 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 16287 T1536 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 16287 T1536 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 16287 T1536 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 16288 T1536 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 16288 T1536 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 16288 T1536 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 16288 T1536 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 16289 T1536 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 16289 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 16294 T1536 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 16312 T1536 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:43174/solr
[junit4:junit4]   2> 16312 T1536 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 16312 T1536 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:43174 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@b56b3a
[junit4:junit4]   2> 16313 T1536 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 16313 T1624 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:43174. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 16314 T1624 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:43174, initiating session
[junit4:junit4]   2> 16314 T1538 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38680
[junit4:junit4]   2> 16315 T1538 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38680
[junit4:junit4]   2> 16316 T1540 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d9bb6245f000b with negotiated timeout 20000 for client /127.0.0.1:38680
[junit4:junit4]   2> 16316 T1624 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:43174, sessionid = 0x13d9bb6245f000b, negotiated timeout = 20000
[junit4:junit4]   2> 16317 T1625 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b56b3a name:ZooKeeperConnection Watcher:127.0.0.1:43174 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 16317 T1536 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 16318 T1541 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d9bb6245f000b
[junit4:junit4]   2> 16319 T1625 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 16319 T1538 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:38680 which had sessionid 0x13d9bb6245f000b
[junit4:junit4]   2> 16319 T1536 oaz.ZooKeeper.close Session: 0x13d9bb6245f000b closed
[junit4:junit4]   2> 16320 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 16324 T1536 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:43174/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@d1076f
[junit4:junit4]   2> 16325 T1626 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:43174. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 16325 T1536 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 16325 T1626 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:43174, initiating session
[junit4:junit4]   2> 16325 T1538 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38681
[junit4:junit4]   2> 16326 T1538 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38681
[junit4:junit4]   2> 16326 T1540 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d9bb6245f000c with negotiated timeout 20000 for client /127.0.0.1:38681
[junit4:junit4]   2> 16327 T1626 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:43174, sessionid = 0x13d9bb6245f000c, negotiated timeout = 20000
[junit4:junit4]   2> 16327 T1627 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d1076f name:ZooKeeperConnection Watcher:127.0.0.1:43174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 16327 T1536 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 16328 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f000c type:create cxid:0x1 zxid:0xa1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 16331 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f000c type:create cxid:0x3 zxid:0xa2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 16335 T1536 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 17173 T1559 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 17174 T1559 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:39659_gn_sex%2Fc_collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:39659_gn_sex%2Fc",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:39659/gn_sex/c",
[junit4:junit4]   2> 	  "shard":"shard1"}
[junit4:junit4]   2> 17181 T1627 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> 17182 T1565 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> 17183 T1594 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> 17183 T1578 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> 17181 T1610 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> 17181 T1558 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> 17216 T1571 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {onlyIfLeader=true&wt=javabin&state=recovering&coreNodeName=127.0.0.1:39659_gn_sex%252Fc_collection1&version=2&checkLive=true&core=collection1&nodeName=127.0.0.1:39659_gn_sex%252Fc&action=PREPRECOVERY} status=0 QTime=1000 
[junit4:junit4]   2> 17339 T1536 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36167_gn_sex%2Fc
[junit4:junit4]   2> 17341 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f000c type:delete cxid:0xf zxid:0xa7 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:36167_gn_sex%2Fc Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:36167_gn_sex%2Fc
[junit4:junit4]   2> 17342 T1536 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36167_gn_sex%2Fc
[junit4:junit4]   2> 17346 T1594 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> 17346 T1558 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> 17347 T1610 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17347 T1627 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17347 T1578 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17347 T1565 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17347 T1578 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 17347 T1610 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 17348 T1627 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 17348 T1565 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 17350 T1594 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17350 T1558 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17358 T1628 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-jetty4-1364117054382/collection1
[junit4:junit4]   2> 17358 T1628 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 17359 T1628 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 17359 T1628 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 17362 T1628 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-jetty4-1364117054382/collection1/'
[junit4:junit4]   2> 17362 T1628 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1364117054382/collection1/lib/README' to classloader
[junit4:junit4]   2> 17363 T1628 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1364117054382/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 17402 T1628 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 17426 T1628 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 17427 T1628 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 17430 T1628 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 17698 T1628 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 17702 T1628 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 17704 T1628 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 17723 T1628 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 17728 T1628 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 17732 T1628 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 17734 T1628 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 17735 T1628 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 17735 T1628 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 17737 T1628 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 17738 T1628 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 17738 T1628 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 17738 T1628 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-jetty4-1364117054382/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty4/
[junit4:junit4]   2> 17738 T1628 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@164387c
[junit4:junit4]   2> 17739 T1628 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 17740 T1628 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty4
[junit4:junit4]   2> 17740 T1628 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty4/index/
[junit4:junit4]   2> 17740 T1628 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 17740 T1628 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty4/index
[junit4:junit4]   2> 17742 T1628 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1f55aa4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@60a752),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 17743 T1628 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 17745 T1628 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 17746 T1628 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 17746 T1628 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 17747 T1628 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 17748 T1628 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 17748 T1628 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 17749 T1628 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 17749 T1628 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 17750 T1628 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 17754 T1628 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 17758 T1628 oass.SolrIndexSearcher.<init> Opening Searcher@1bc65d1 main
[junit4:junit4]   2> 17758 T1628 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty4/tlog
[junit4:junit4]   2> 17759 T1628 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 17759 T1628 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 17764 T1629 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1bc65d1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 17766 T1628 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 17767 T1628 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 18691 T1559 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18692 T1559 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:36167_gn_sex%2Fc",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:36167/gn_sex/c",
[junit4:junit4]   2> 	  "shard":null}
[junit4:junit4]   2> 18693 T1559 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 18693 T1559 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4]   2> 18700 T1578 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18700 T1565 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18700 T1558 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18700 T1627 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18700 T1594 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18700 T1610 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18769 T1628 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 18769 T1628 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36167/gn_sex/c collection:collection1 shard:shard2
[junit4:junit4]   2> 18774 T1628 oasc.ZkController.register We are http://127.0.0.1:36167/gn_sex/c/collection1/ and leader is http://127.0.0.1:34680/gn_sex/c/collection1/
[junit4:junit4]   2> 18775 T1628 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36167/gn_sex/c
[junit4:junit4]   2> 18775 T1628 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 18775 T1628 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C100 name=collection1 org.apache.solr.core.SolrCore@58b736 url=http://127.0.0.1:36167/gn_sex/c/collection1 node=127.0.0.1:36167_gn_sex%2Fc C100_STATE=coll:collection1 core:collection1 props:{collection=collection1, state=down, node_name=127.0.0.1:36167_gn_sex%2Fc, core=collection1, base_url=http://127.0.0.1:36167/gn_sex/c}
[junit4:junit4]   2> 18776 T1630 C100 P36167 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 18777 T1630 C100 P36167 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 18777 T1630 C100 P36167 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 18777 T1628 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18777 T1630 C100 P36167 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 18779 T1630 C100 P36167 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 18779 T1536 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   2> 18780 T1536 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 18781 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 18786 T1536 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18788 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 18794 T1571 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-1364117041678/onenodecollectioncore
[junit4:junit4]   2> 18794 T1571 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4]   2> 18796 T1571 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4]   2> 18796 T1571 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4]   2> 18799 T1571 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4]   2> 18799 T1571 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4]   2> 18803 T1571 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4]   2> 18806 T1571 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-1364117041678/onenodecollectioncore/'
[junit4:junit4]   2> 18854 T1571 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 18882 T1571 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 18883 T1571 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 18886 T1571 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 19152 T1571 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 19157 T1571 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 19159 T1571 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 19174 T1571 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 19178 T1571 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 19181 T1571 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 19183 T1571 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 19184 T1571 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 19184 T1571 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 19186 T1571 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 19186 T1571 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 19186 T1571 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 19186 T1571 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-1364117041678/onenodecollectioncore/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1364117038171/onenodecollection/
[junit4:junit4]   2> 19187 T1571 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@164387c
[junit4:junit4]   2> 19187 T1571 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 19188 T1571 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1364117038171/onenodecollection
[junit4:junit4]   2> 19189 T1571 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-1364117038171/onenodecollection/index/
[junit4:junit4]   2> 19189 T1571 oasc.SolrCore.initIndex WARNING [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1364117038171/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 19190 T1571 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1364117038171/onenodecollection/index
[junit4:junit4]   2> 19192 T1571 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1449bfa lockFactory=org.apache.lucene.store.NativeFSLockFactory@f19a21),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 19193 T1571 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 19196 T1571 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 19196 T1571 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 19197 T1571 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 19198 T1571 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 19199 T1571 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 19199 T1571 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 19199 T1571 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 19200 T1571 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 19200 T1571 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 19202 T1571 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 19204 T1571 oass.SolrIndexSearcher.<init> Opening Searcher@58be26 main
[junit4:junit4]   2> 19204 T1571 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1364117038171/onenodecollection/tlog
[junit4:junit4]   2> 19205 T1571 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 19205 T1571 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 19209 T1632 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@58be26 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 19211 T1571 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4]   2>  C99_STATE=coll:collection1 core:collection1 props:{collection=collection1, state=recovering, node_name=127.0.0.1:39659_gn_sex%2Fc, core=collection1, base_url=http://127.0.0.1:39659/gn_sex/c, shard=shard1}
[junit4:junit4]   2> 19218 T1613 C99 P39659 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:58596/gn_sex/c/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 19218 T1613 C99 P39659 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:39659/gn_sex/c START replicas=[http://127.0.0.1:58596/gn_sex/c/collection1/] nUpdates=100
[junit4:junit4]   2> 19219 T1613 C99 P39659 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 19219 T1613 C99 P39659 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 19220 T1613 C99 P39659 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 19220 T1613 C99 P39659 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 19220 T1613 C99 P39659 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 19220 T1613 C99 P39659 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:58596/gn_sex/c/collection1/. core=collection1
[junit4:junit4]   2> 19220 T1613 C99 P39659 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C101 name=collection1 org.apache.solr.core.SolrCore@b4ab25 url=http://127.0.0.1:58596/gn_sex/c/collection1 node=127.0.0.1:58596_gn_sex%2Fc C101_STATE=coll:collection1 core:collection1 props:{collection=collection1, state=active, node_name=127.0.0.1:58596_gn_sex%2Fc, core=collection1, base_url=http://127.0.0.1:58596/gn_sex/c, shard=shard1, leader=true}
[junit4:junit4]   2> 19226 T1574 C101 P58596 REQ /get {wt=javabin&qt=/get&version=2&distrib=false&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 19227 T1572 C101 P58596 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 19230 T1572 C101 P58596 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1b2ec70 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a741f3),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 19231 T1572 C101 P58596 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 19232 T1572 C101 P58596 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1b2ec70 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a741f3),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1b2ec70 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a741f3),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 19232 T1572 C101 P58596 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 19233 T1572 C101 P58596 oass.SolrIndexSearcher.<init> Opening Searcher@ca83cf realtime
[junit4:junit4]   2> 19233 T1572 C101 P58596 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 19234 T1572 C101 P58596 /update {softCommit=false&commit=true&commit_end_point=true&wt=javabin&version=2&waitSearcher=true&openSearcher=false} {commit=} 0 7
[junit4:junit4]   2> 19235 T1613 C99 P39659 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 19235 T1613 C99 P39659 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 19241 T1574 C101 P58596 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 19242 T1574 C101 P58596 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 19243 T1613 C99 P39659 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 19243 T1613 C99 P39659 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 19243 T1613 C99 P39659 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 19246 T1572 C101 P58596 REQ /replication {command=filelist&qt=/replication&wt=javabin&version=2&generation=2} status=0 QTime=0 
[junit4:junit4]   2> 19247 T1613 C99 P39659 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 19249 T1613 C99 P39659 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty3/index.20130324202417415
[junit4:junit4]   2> 19249 T1613 C99 P39659 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@3eb22 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5c121a) fullCopy=false
[junit4:junit4]   2> 19252 T1573 C101 P58596 REQ /replication {command=filecontent&wt=filestream&qt=/replication&generation=2&file=segments_2&checksum=true} status=0 QTime=0 
[junit4:junit4]   2> 19254 T1613 C99 P39659 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 19255 T1613 C99 P39659 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 19255 T1613 C99 P39659 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 19257 T1613 C99 P39659 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@185c20f lockFactory=org.apache.lucene.store.NativeFSLockFactory@8c480e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@185c20f lockFactory=org.apache.lucene.store.NativeFSLockFactory@8c480e),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 19258 T1613 C99 P39659 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 19258 T1613 C99 P39659 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 19258 T1613 C99 P39659 oass.SolrIndexSearcher.<init> Opening Searcher@1abbb6a main
[junit4:junit4]   2> 19260 T1612 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1abbb6a main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 19260 T1613 C99 P39659 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 19261 T1613 C99 P39659 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 19261 T1613 C99 P39659 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 19261 T1613 C99 P39659 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 19263 T1613 C99 P39659 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 20210 T1559 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20211 T1559 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:36167_gn_sex%2Fc_collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:36167_gn_sex%2Fc",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:36167/gn_sex/c",
[junit4:junit4]   2> 	  "shard":"shard2"}
[junit4:junit4]   2> 20218 T1559 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "collection":"onenodecollection",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:58596_gn_sex%2Fc",
[junit4:junit4]   2> 	  "roles":"none",
[junit4:junit4]   2> 	  "core":"onenodecollectioncore",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:58596/gn_sex/c",
[junit4:junit4]   2> 	  "shard":null}
[junit4:junit4]   2> 20218 T1559 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4]   2> 20218 T1559 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 20226 T1559 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:39659_gn_sex%2Fc_collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:39659_gn_sex%2Fc",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:39659/gn_sex/c",
[junit4:junit4]   2> 	  "shard":"shard1"}
[junit4:junit4]   2> 20232 T1610 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20232 T1558 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20232 T1565 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20232 T1627 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20232 T1594 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20232 T1578 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20787 T1589 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {onlyIfLeader=true&wt=javabin&state=recovering&coreNodeName=127.0.0.1:36167_gn_sex%252Fc_collection1&version=2&checkLive=true&core=collection1&nodeName=127.0.0.1:36167_gn_sex%252Fc&action=PREPRECOVERY} status=0 QTime=2001 
[junit4:junit4]   2> 21213 T1571 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4]   2> 21214 T1571 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:58596/gn_sex/c collection:onenodecollection shard:shard1
[junit4:junit4]   2> 21215 T1571 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4]   2> 21227 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0006 type:delete cxid:0xac zxid:0xc2 txntype:-1 reqpath:n/a Error Path:/solr/collections/onenodecollection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/onenodecollection/leaders
[junit4:junit4]   2> 21228 T1571 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 21229 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0006 type:create cxid:0xad zxid:0xc3 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 21233 T1571 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 21233 T1571 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 21233 T1571 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58596/gn_sex/c/onenodecollectioncore/
[junit4:junit4]   2> 21234 T1571 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 21234 T1571 oasc.SyncStrategy.syncToMe http://127.0.0.1:58596/gn_sex/c/onenodecollectioncore/ has no replicas
[junit4:junit4]   2> 21235 T1571 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58596/gn_sex/c/onenodecollectioncore/
[junit4:junit4]   2> 21235 T1571 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4]   2> 21242 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0006 type:create cxid:0xb8 zxid:0xc7 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 21747 T1559 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 21761 T1578 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 21761 T1594 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 21761 T1610 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 21761 T1558 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 21761 T1565 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 21761 T1627 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 21797 T1571 oasc.ZkController.register We are http://127.0.0.1:58596/gn_sex/c/onenodecollectioncore/ and leader is http://127.0.0.1:58596/gn_sex/c/onenodecollectioncore/
[junit4:junit4]   2> 21798 T1571 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:58596/gn_sex/c
[junit4:junit4]   2> 21798 T1571 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 21798 T1571 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4]   2> 21801 T1571 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 21803 T1571 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {collection=onenodecollection&numShards=1&wt=javabin&version=2&roles=none&dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1364117038171/onenodecollection&name=onenodecollectioncore&action=CREATE} status=0 QTime=3009 
[junit4:junit4]   2> 21804 T1536 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4]   2> 21805 T1536 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C100_STATE=coll:collection1 core:collection1 props:{collection=collection1, state=recovering, node_name=127.0.0.1:36167_gn_sex%2Fc, core=collection1, base_url=http://127.0.0.1:36167/gn_sex/c, shard=shard2}
[junit4:junit4]   2> 22788 T1630 C100 P36167 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:34680/gn_sex/c/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 22788 T1630 C100 P36167 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:36167/gn_sex/c START replicas=[http://127.0.0.1:34680/gn_sex/c/collection1/] nUpdates=100
[junit4:junit4]   2> 22789 T1630 C100 P36167 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 22789 T1630 C100 P36167 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 22789 T1630 C100 P36167 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 22790 T1630 C100 P36167 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 22790 T1630 C100 P36167 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 22790 T1630 C100 P36167 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:34680/gn_sex/c/collection1/. core=collection1
[junit4:junit4]   2> 22790 T1630 C100 P36167 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C102 name=collection1 org.apache.solr.core.SolrCore@abe71 url=http://127.0.0.1:34680/gn_sex/c/collection1 node=127.0.0.1:34680_gn_sex%2Fc C102_STATE=coll:collection1 core:collection1 props:{collection=collection1, state=active, node_name=127.0.0.1:34680_gn_sex%2Fc, core=collection1, base_url=http://127.0.0.1:34680/gn_sex/c, shard=shard2, leader=true}
[junit4:junit4]   2> 22797 T1589 C102 P34680 REQ /get {wt=javabin&qt=/get&version=2&distrib=false&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 22801 T1590 C102 P34680 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 22804 T1590 C102 P34680 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e5a9f lockFactory=org.apache.lucene.store.NativeFSLockFactory@6780f5),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 22805 T1590 C102 P34680 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 22806 T1590 C102 P34680 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e5a9f lockFactory=org.apache.lucene.store.NativeFSLockFactory@6780f5),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e5a9f lockFactory=org.apache.lucene.store.NativeFSLockFactory@6780f5),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 22806 T1590 C102 P34680 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 22807 T1590 C102 P34680 oass.SolrIndexSearcher.<init> Opening Searcher@6d3585 realtime
[junit4:junit4]   2> 22807 T1590 C102 P34680 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 22808 T1590 C102 P34680 /update {softCommit=false&commit=true&commit_end_point=true&wt=javabin&version=2&waitSearcher=true&openSearcher=false} {commit=} 0 7
[junit4:junit4]   2> 22808 T1536 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22809 T1630 C100 P36167 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 22809 T1630 C100 P36167 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 22812 T1588 C102 P34680 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 22812 T1588 C102 P34680 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 22813 T1630 C100 P36167 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 22813 T1630 C100 P36167 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 22813 T1630 C100 P36167 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 22816 T1589 C102 P34680 REQ /replication {command=filelist&qt=/replication&wt=javabin&version=2&generation=2} status=0 QTime=0 
[junit4:junit4]   2> 22817 T1630 C100 P36167 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 22818 T1630 C100 P36167 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/jetty4/index.20130324202420985
[junit4:junit4]   2> 22819 T1630 C100 P36167 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@1f9c4ed lockFactory=org.apache.lucene.store.NativeFSLockFactory@18818fb) fullCopy=false
[junit4:junit4]   2> 22822 T1590 C102 P34680 REQ /replication {command=filecontent&wt=filestream&qt=/replication&generation=2&file=segments_2&checksum=true} status=0 QTime=1 
[junit4:junit4]   2> 22823 T1630 C100 P36167 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 22825 T1630 C100 P36167 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 22825 T1630 C100 P36167 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 22826 T1630 C100 P36167 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1f55aa4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@60a752),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1f55aa4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@60a752),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 22827 T1630 C100 P36167 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 22827 T1630 C100 P36167 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 22828 T1630 C100 P36167 oass.SolrIndexSearcher.<init> Opening Searcher@53f8d8 main
[junit4:junit4]   2> 22829 T1629 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@53f8d8 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 22830 T1630 C100 P36167 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 22830 T1630 C100 P36167 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 22830 T1630 C100 P36167 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 22830 T1630 C100 P36167 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 22832 T1630 C100 P36167 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 23271 T1559 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 23273 T1559 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "collection":"onenodecollection",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:58596_gn_sex%2Fc_onenodecollectioncore",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:58596_gn_sex%2Fc",
[junit4:junit4]   2> 	  "roles":"none",
[junit4:junit4]   2> 	  "core":"onenodecollectioncore",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:58596/gn_sex/c",
[junit4:junit4]   2> 	  "shard":"shard1"}
[junit4:junit4]   2> 23278 T1559 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:36167_gn_sex%2Fc_collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:36167_gn_sex%2Fc",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:36167/gn_sex/c",
[junit4:junit4]   2> 	  "shard":"shard2"}
[junit4:junit4]   2> 23285 T1578 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 23285 T1594 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 23285 T1565 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 23285 T1610 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 23285 T1627 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 23285 T1558 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 23811 T1536 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 23813 T1536 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4]   2> 23813 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 23821 T1536 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:43174 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@154d472
[junit4:junit4]   2> 23822 T1637 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:43174. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 23822 T1536 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 23823 T1637 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:43174, initiating session
[junit4:junit4]   2> 23823 T1538 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38691
[junit4:junit4]   2> 23823 T1538 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38691
[junit4:junit4]   2> 23824 T1540 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d9bb6245f000d with negotiated timeout 10000 for client /127.0.0.1:38691
[junit4:junit4]   2> 23825 T1637 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:43174, sessionid = 0x13d9bb6245f000d, negotiated timeout = 10000
[junit4:junit4]   2> 23825 T1638 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@154d472 name:ZooKeeperConnection Watcher:127.0.0.1:43174 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 23825 T1536 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[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/configs (1)
[junit4:junit4]   1>    /solr/configs/conf1 (9)
[junit4:junit4]   1>     /solr/configs/conf1/schema.xml (0)
[junit4:junit4]   1>     DATA: ...supressed...
[junit4:junit4]   1>     /solr/configs/conf1/mapping-ISOLatin1Accent.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/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/protwords.txt (0)
[junit4:junit4]   1>     DATA: ...supressed...
[junit4:junit4]   1>     /solr/configs/conf1/synonyms.txt (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/old_synonyms.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/overseer_elect (2)
[junit4:junit4]   1>    /solr/overseer_elect/leader (0)
[junit4:junit4]   1>    DATA:
[junit4:junit4]   1>        {"id":"89398774213836803-127.0.0.1:57200_gn_sex%2Fc-n_0000000000"}
[junit4:junit4]   1>    /solr/overseer_elect/election (5)
[junit4:junit4]   1>     /solr/overseer_elect/election/89398774213836810-127.0.0.1:39659_gn_sex%2Fc-n_0000000003 (0)
[junit4:junit4]   1>     /solr/overseer_elect/election/89398774213836812-127.0.0.1:36167_gn_sex%2Fc-n_0000000004 (0)
[junit4:junit4]   1>     /solr/overseer_elect/election/89398774213836803-127.0.0.1:57200_gn_sex%2Fc-n_0000000000 (0)
[junit4:junit4]   1>     /solr/overseer_elect/election/89398774213836808-127.0.0.1:34680_gn_sex%2Fc-n_0000000002 (0)
[junit4:junit4]   1>     /solr/overseer_elect/election/89398774213836806-127.0.0.1:58596_gn_sex%2Fc-n_0000000001 (0)
[junit4:junit4]   1>   /solr/overseer (3)
[junit4:junit4]   1>   DATA:
[junit4:junit4]   1>       
[junit4:junit4]   1>    /solr/overseer/queue (0)
[junit4:junit4]   1>    /solr/overseer/collection-queue-work (0)
[junit4:junit4]   1>    /solr/overseer/queue-work (0)
[junit4:junit4]   1>   /solr/live_nodes (5)
[junit4:junit4]   1>    /solr/live_nodes/127.0.0.1:34680_gn_sex%2Fc (0)
[junit4:junit4]   1>    /solr/live_nodes/127.0.0.1:58596_gn_sex%2Fc (0)
[junit4:junit4]   1>    /solr/live_nodes/127.0.0.1:36167_gn_sex%2Fc (0)
[junit4:junit4]   1>    /solr/live_nodes/127.0.0.1:39659_gn_sex%2Fc (0)
[junit4:junit4]   1>    /solr/live_nodes/127.0.0.1:57200_gn_sex%2Fc (0)
[junit4:junit4]   1>   /solr/aliases.json (0)
[junit4:junit4]   1>   /solr/collections (3)
[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>            "node_name":"127.0.0.1:58596_gn_sex%2Fc",
[junit4:junit4]   1>            "core":"collection1",
[junit4:junit4]   1>            "base_url":"http://127.0.0.1:58596/gn_sex/c"}
[junit4:junit4]   1>      /solr/collections/collection1/leaders/shard2 (0)
[junit4:junit4]   1>      DATA:
[junit4:junit4]   1>          {
[junit4:junit4]   1>            "node_name":"127.0.0.1:34680_gn_sex%2Fc",
[junit4:junit4]   1>            "core":"collection1",
[junit4:junit4]   1>            "base_url":"http://127.0.0.1:34680/gn_sex/c"}
[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 (2)
[junit4:junit4]   1>        /solr/collections/collection1/leader_elect/shard1/election/89398774213836810-127.0.0.1:39659_gn_sex%2Fc_collection1-n_0000000001 (0)
[junit4:junit4]   1>        /solr/collections/collection1/leader_elect/shard1/election/89398774213836806-127.0.0.1:58596_gn_sex%2Fc_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/89398774213836812-127.0.0.1:36167_gn_sex%2Fc_collection1-n_0000000001 (0)
[junit4:junit4]   1>        /solr/collections/collection1/leader_elect/shard2/election/89398774213836808-127.0.0.1:34680_gn_sex%2Fc_collection1-n_0000000000 (0)
[junit4:junit4]   1>     /solr/collections/collection1/shards (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>            "node_name":"127.0.0.1:57200_gn_sex%2Fc",
[junit4:junit4]   1>            "core":"collection1",
[junit4:junit4]   1>            "base_url":"http://127.0.0.1:57200/gn_sex/c"}
[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/89398774213836803-127.0.0.1:57200_gn_sex%2Fc_collection1-n_0000000000 (0)
[junit4:junit4]   1>     /solr/collections/control_collection/shards (0)
[junit4:junit4]   1>    /solr/collections/onenodecollection (2)
[junit4:junit4]   1>    DATA:
[junit4:junit4]   1>        {
[junit4:junit4]   1>          "router":"compositeId",
[junit4:junit4]   1>          "configName":"conf1"}
[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>            "node_name":"127.0.0.1:58596_gn_sex%2Fc",
[junit4:junit4]   1>            "core":"onenodecollectioncore",
[junit4:junit4]   1>            "base_url":"http://127.0.0.1:58596/gn_sex/c"}
[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/89398774213836806-127.0.0.1:58596_gn_sex%2Fc_onenodecollectioncore-n_0000000000 (0)
[junit4:junit4]   1>   /solr/clusterstate.json (0)
[junit4:junit4]   1>   DATA:
[junit4:junit4]   1>       {
[junit4:junit4]   1>         "onenodecollection":{
[junit4:junit4]   1>           "router":"compositeId",
[junit4:junit4]   1>           "shards":{"shard1":{
[junit4:junit4]   1>               "range":"80000000-7fffffff",
[junit4:junit4]   1>               "state":"active",
[junit4:junit4]   1>               "replicas":{"127.0.0.1:58596_gn_sex%2Fc_onenodecollectioncore":{
[junit4:junit4]   1>                   "collection":"onenodecollection",
[junit4:junit4]   1>                   "state":"active",
[junit4:junit4]   1>                   "node_name":"127.0.0.1:58596_gn_sex%2Fc",
[junit4:junit4]   1>                   "roles":"none",
[junit4:junit4]   1>                   "core":"onenodecollectioncore",
[junit4:junit4]   1>                   "base_url":"http://127.0.0.1:58596/gn_sex/c",
[junit4:junit4]   1>                   "shard":"shard1",
[junit4:junit4]   1>                   "leader":"true"}}}}},
[junit4:junit4]   1>         "collection1":{
[junit4:junit4]   1>           "router":"compositeId",
[junit4:junit4]   1>           "shards":{
[junit4:junit4]   1>             "shard1":{
[junit4:junit4]   1>               "range":"80000000-ffffffff",
[junit4:junit4]   1>               "state":"active",
[junit4:junit4]   1>               "replicas":{
[junit4:junit4]   1>                 "127.0.0.1:58596_gn_sex%2Fc_collection1":{
[junit4:junit4]   1>                   "collection":"collection1",
[junit4:junit4]   1>                   "state":"active",
[junit4:junit4]   1>                   "node_name":"127.0.0.1:58596_gn_sex%2Fc",
[junit4:junit4]   1>                   "core":"collection1",
[junit4:junit4]   1>                   "base_url":"http://127.0.0.1:58596/gn_sex/c",
[junit4:junit4]   1>                   "shard":"shard1",
[junit4:junit4]   1>                   "leader":"true"},
[junit4:junit4]   1>                 "127.0.0.1:39659_gn_sex%2Fc_collection1":{
[junit4:junit4]   1>                   "collection":"collection1",
[junit4:junit4]   1>                   "state":"active",
[junit4:junit4]   1>                   "node_name":"127.0.0.1:39659_gn_sex%2Fc",
[junit4:junit4]   1>                   "core":"collection1",
[junit4:junit4]   1>                   "base_url":"http://127.0.0.1:39659/gn_sex/c",
[junit4:junit4]   1>                   "shard":"shard1"}}},
[junit4:junit4]   1>             "shard2":{
[junit4:junit4]   1>               "range":"0-7fffffff",
[junit4:junit4]   1>               "state":"active",
[junit4:junit4]   1>               "replicas":{
[junit4:junit4]   1>                 "127.0.0.1:34680_gn_sex%2Fc_collection1":{
[junit4:junit4]   1>                   "collection":"collection1",
[junit4:junit4]   1>                   "state":"active",
[junit4:junit4]   1>                   "node_name":"127.0.0.1:34680_gn_sex%2Fc",
[junit4:junit4]   1>                   "core":"collection1",
[junit4:junit4]   1>                   "base_url":"http://127.0.0.1:34680/gn_sex/c",
[junit4:junit4]   1>                   "shard":"shard2",
[junit4:junit4]   1>                   "leader":"true"},
[junit4:junit4]   1>                 "127.0.0.1:36167_gn_sex%2Fc_collection1":{
[junit4:junit4]   1>                   "collection":"collection1",
[junit4:junit4]   1>                   "state":"active",
[junit4:junit4]   1>                   "node_name":"127.0.0.1:36167_gn_sex%2Fc",
[junit4:junit4]   1>                   "core":"collection1",
[junit4:junit4]   1>                   "base_url":"http://127.0.0.1:36167/gn_sex/c",
[junit4:junit4]   1>                   "shard":"shard2"}}}}},
[junit4:junit4]   1>         "control_collection":{
[junit4:junit4]   1>           "router":"compositeId",
[junit4:junit4]   1>           "shards":{"shard1":{
[junit4:junit4]   1>               "range":"80000000-7fffffff",
[junit4:junit4]   1>               "state":"active",
[junit4:junit4]   1>               "replicas":{"127.0.0.1:57200_gn_sex%2Fc_collection1":{
[junit4:junit4]   2> 23917 T1541 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d9bb6245f000d
[junit4:junit4]   2> 23918 T1638 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 23918 T1538 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:38691 which had sessionid 0x13d9bb6245f000d
[junit4:junit4]   2> 23918 T1536 oaz.ZooKeeper.close Session: 0x13d9bb6245f000d closed
[junit4:junit4]   2> 23919 T1541 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d9bb6245f0004
[junit4:junit4]   2> 23920 T1565 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 23920 T1538 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:38635 which had sessionid 0x13d9bb6245f0004
[junit4:junit4]   2> 23920 T1536 oaz.ZooKeeper.close Session: 0x13d9bb6245f0004 closed
[junit4:junit4]   2> 23924 T1536 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 57200
[junit4:junit4]   2> 23925 T1536 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=23034514
[junit4:junit4]   2> 24795 T1559 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 24796 T1559 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:57200_gn_sex%2Fc_collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:57200_gn_sex%2Fc",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:57200/gn_sex/c",
[junit4:junit4]   2> 	  "shard":"shard1"}
[junit4:junit4]   2> 24804 T1594 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 24804 T1578 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 24804 T1610 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 24804 T1627 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 24804 T1558 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 25927 T1536 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 25928 T1536 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 25932 T1536 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@1467542
[junit4:junit4]   2> 25937 T1536 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> 25938 T1536 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 25938 T1536 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 25939 T1536 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 25940 T1536 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 25941 T1536 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/control/data/index
[junit4:junit4]   2> 25942 T1536 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/control/data/index
[junit4:junit4]   2> 25942 T1536 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/control/data
[junit4:junit4]   2> 25943 T1536 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1364117038171/control/data
[junit4:junit4]   2> 25945 T1559 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89398774213836803-127.0.0.1:57200_gn_sex%2Fc-n_0000000000) am no longer a leader.
[junit4:junit4]   2> 25945 T1541 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d9bb6245f0003
[junit4:junit4]   2> 25946 T1594 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 25947 T1538 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:38634 which had sessionid 0x13d9bb6245f0003
[junit4:junit4]   2> 25947 T1536 oaz.ZooKeeper.close Session: 0x13d9bb6245f0003 closed
[junit4:junit4]   2> 25948 T1627 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 25948 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0006 type:delete cxid:0xc6 zxid:0xe3 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 25948 T1610 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 25948 T1627 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> 25949 T1610 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> 25949 T1578 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 25950 T1594 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 25953 T1578 oasc.Overseer.start Overseer (id=89398774213836806-127.0.0.1:58596_gn_sex%2Fc-n_0000000001) starting
[junit4:junit4]   2> 25953 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0006 type:create cxid:0xcb zxid:0xe5 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 25955 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0006 type:create cxid:0xcc zxid:0xe6 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 25957 T1541 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d9bb6245f0006 type:create cxid:0xce zxid:0xe7 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists fo

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

Search <<<
[junit4:junit4]    > Throwable #1: org.apache.solr.common.SolrException: Server at http://127.0.0.1:34680/gn_sex/c/onenodecollectioncore returned non ok status:404, message:Can not find: /gn_sex/c/onenodecollectioncore/update
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([414EDA31D46C28C1:C0A85429A33348FD]:0)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:375)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
[junit4:junit4]    > 	at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:197)
[junit4:junit4]    > 	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:89)
[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> 32454 T1536 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> 32459 T1535 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4]   2> 32545 T1610 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 32545 T1610 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> 32546 T1610 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 32546 T1610 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 32832 T1539 oazs.SessionTrackerImpl.run SessionTrackerImpl exited loop!
[junit4:junit4]   2> NOTE: test params are: codec=Lucene42: {}, docValues:{}, sim=DefaultSimilarity, locale=en_SG, timezone=AET
[junit4:junit4]   2> NOTE: Linux 3.2.0-39-generic i386/Oracle Corporation 1.8.0-ea (32-bit)/cpus=8,threads=2,free=133407224,total=265224192
[junit4:junit4]   2> NOTE: All tests run in this JVM: [ChaosMonkeyNothingIsSafeTest, ResourceLoaderTest, TestRemoteStreaming, TestSearchPerf, ReturnFieldsTest, SolrTestCaseJ4Test, TestPluginEnable, TestWriterPerf, BadComponentTest, AnalysisAfterCoreReloadTest, TestCopyFieldCollectionResource, AlternateDirectoryTest, SpatialFilterTest, CoreAdminHandlerTest, TermsComponentTest, BasicDistributedZkTest, CircularListTest, SearchHandlerTest, SystemInfoHandlerTest, TestQueryUtils, DocValuesTest, SuggesterTest, TestQuerySenderListener, IndexSchemaTest, AutoCommitTest, TestSweetSpotSimilarityFactory, JsonLoaderTest, RegexBoostProcessorTest, ZkCLITest, SynonymTokenizerTest, TestShardHandlerFactory, ShowFileRequestHandlerTest, PolyFieldTest, TestFastWriter, TestFuzzyAnalyzedSuggestions, RAMDirectoryFactoryTest, TestPseudoReturnFields, ResponseLogComponentTest, TestStressVersions, DistributedTermsComponentTest, StatelessScriptUpdateProcessorFactoryTest, SoftAutoCommitTest, MoreLikeThisHandlerTest, PluginInfoTest, DateFieldTest, TestSolrIndexConfig, PrimUtilsTest, DistributedQueryElevationComponentTest, TestIBSimilarityFactory, TestFieldTypeResource, DistributedSpellCheckComponentTest, FastVectorHighlighterTest, SolrIndexSplitterTest, BasicFunctionalityTest, ZkControllerTest, PrimitiveFieldTypeTest, CSVRequestHandlerTest, TestJoin, TestPerFieldSimilarity, SchemaVersionSpecificBehaviorTest, TestStressRecovery, TestGroupingSearch, QueryEqualityTest, SliceStateUpdateTest, LeaderElectionTest, TestDynamicFieldCollectionResource, TestFastLRUCache, BasicDistributedZk2Test]
[junit4:junit4] Completed on J0 in 32.98s, 1 test, 1 error <<< FAILURES!

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

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



Mime
View raw message