lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-NightlyTests-4.x - Build # 466 - Still Failing
Date Mon, 23 Dec 2013 02:27:15 GMT
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-4.x/466/

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

Error Message:
No live SolrServers available to handle this request:[http://127.0.0.1:56900/lx_/h/collection1, http://127.0.0.1:30267/lx_/h/collection1]

Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:56900/lx_/h/collection1, http://127.0.0.1:30267/lx_/h/collection1]
	at __randomizedtesting.SeedInfo.seed([711212906387DA43:F0F49C8814D8BA7F]:0)
	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:352)
	at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:640)
	at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:90)
	at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.queryServer(AbstractFullDistribZkTestBase.java:1325)
	at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:542)
	at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:521)
	at org.apache.solr.cloud.BasicDistributedZk2Test.brindDownShardIndexSomeDocsAndRecover(BasicDistributedZk2Test.java:305)
	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:117)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:849)
	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:616)
	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:679)
Caused by: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: no servers hosting shard: 
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:495)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:283)
	... 49 more




Build Log:
[...truncated 9668 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
   [junit4]   2> 1019990 T3565 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /lx_/h
   [junit4]   2> 1019996 T3565 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1387763300901
   [junit4]   2> 1019998 T3565 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1019999 T3566 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1020100 T3565 oasc.ZkTestServer.run start zk server on port:22476
   [junit4]   2> 1020102 T3565 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1020109 T3572 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5670ae48 name:ZooKeeperConnection Watcher:127.0.0.1:22476 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1020109 T3565 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1020110 T3565 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1020115 T3565 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1020124 T3574 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19dc8a19 name:ZooKeeperConnection Watcher:127.0.0.1:22476/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1020124 T3565 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1020125 T3565 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1020128 T3565 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1020137 T3565 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1020139 T3565 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1020142 T3565 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1020143 T3565 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1020148 T3565 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 1020149 T3565 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1020253 T3565 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1020255 T3565 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1020258 T3565 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1020258 T3565 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1020269 T3565 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1020270 T3565 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1020272 T3565 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1020273 T3565 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1020276 T3565 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 1020277 T3565 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 1020279 T3565 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1020280 T3565 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1020283 T3565 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1020284 T3565 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1020287 T3565 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1020287 T3565 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1020290 T3565 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1020291 T3565 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1020572 T3565 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1020579 T3565 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:52968
   [junit4]   2> 1020580 T3565 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1020581 T3565 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1020581 T3565 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1387763301202
   [junit4]   2> 1020582 T3565 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1387763301202/'
   [junit4]   2> 1020624 T3565 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1387763301202/solr.xml
   [junit4]   2> 1020718 T3565 oasc.CoreContainer.<init> New CoreContainer 2019316404
   [junit4]   2> 1020719 T3565 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1387763301202/]
   [junit4]   2> 1020721 T3565 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1020722 T3565 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1020722 T3565 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1020723 T3565 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1020723 T3565 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1020724 T3565 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1020725 T3565 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1020725 T3565 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1020726 T3565 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1020745 T3565 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1020746 T3565 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1020746 T3565 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1020747 T3565 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:22476/solr
   [junit4]   2> 1020748 T3565 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1020749 T3565 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1020753 T3585 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7539e527 name:ZooKeeperConnection Watcher:127.0.0.1:22476 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1020755 T3565 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1020766 T3565 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1020768 T3587 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@47b5db72 name:ZooKeeperConnection Watcher:127.0.0.1:22476/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1020768 T3565 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1020771 T3565 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1020780 T3565 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1020783 T3565 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1020790 T3565 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52968_lx_%2Fh
   [junit4]   2> 1020792 T3565 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52968_lx_%2Fh
   [junit4]   2> 1020795 T3565 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1020811 T3565 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1020819 T3565 oasc.Overseer.start Overseer (id=90948455688372227-127.0.0.1:52968_lx_%2Fh-n_0000000000) starting
   [junit4]   2> 1020824 T3565 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1020835 T3589 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1020835 T3565 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1020838 T3565 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1020845 T3565 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1020848 T3588 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1020854 T3590 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1020855 T3590 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1020856 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1020856 T3590 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1020857 T3588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1020858 T3588 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52968/lx_/h",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52968_lx_%2Fh",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1020858 T3588 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 1020859 T3588 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1020861 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1020871 T3587 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1021858 T3590 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1021858 T3590 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1387763301202/collection1
   [junit4]   2> 1021859 T3590 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 1021859 T3590 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1021860 T3590 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1021861 T3590 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1387763301202/collection1/'
   [junit4]   2> 1021862 T3590 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1387763301202/collection1/lib/README' to classloader
   [junit4]   2> 1021863 T3590 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1387763301202/collection1/lib/classes/' to classloader
   [junit4]   2> 1021941 T3590 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 1022018 T3590 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1022119 T3590 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1022131 T3590 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1022767 T3590 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1022768 T3590 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1022769 T3590 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1022777 T3590 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1022780 T3590 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1022791 T3590 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1022795 T3590 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1022798 T3590 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1022799 T3590 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1022799 T3590 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1022799 T3590 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1022800 T3590 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1022800 T3590 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1022800 T3590 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1022801 T3590 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1387763301202/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1387763300900/control/data/
   [junit4]   2> 1022801 T3590 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@c569c60
   [junit4]   2> 1022802 T3590 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1387763300900/control/data
   [junit4]   2> 1022802 T3590 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1387763300900/control/data/index/
   [junit4]   2> 1022802 T3590 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1387763300900/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1022803 T3590 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1387763300900/control/data/index
   [junit4]   2> 1022803 T3590 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=75.169921875, floorSegmentMB=1.41015625, forceMergeDeletesPctAllowed=7.465621445085295, segmentsPerTier=33.0, maxCFSSegmentSizeMB=0.6943359375, noCFSRatio=0.49578037389320406
   [junit4]   2> 1022804 T3590 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@2283e745 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7be63ee0; maxCacheMB=0.5947265625 maxMergeSizeMB=0.3359375))),segFN=segments_1,generation=1}
   [junit4]   2> 1022804 T3590 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1022806 T3590 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1022806 T3590 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1022807 T3590 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1022807 T3590 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1022807 T3590 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1022807 T3590 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1022808 T3590 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1022808 T3590 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1022808 T3590 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1022809 T3590 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1022809 T3590 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1022809 T3590 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1022810 T3590 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1022810 T3590 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1022810 T3590 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1022811 T3590 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1022817 T3590 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1022822 T3590 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1022822 T3590 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1022822 T3590 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=19, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1022823 T3590 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@2283e745 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7be63ee0; maxCacheMB=0.5947265625 maxMergeSizeMB=0.3359375))),segFN=segments_1,generation=1}
   [junit4]   2> 1022823 T3590 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1022824 T3590 oass.SolrIndexSearcher.<init> Opening Searcher@13d73476 main
   [junit4]   2> 1022826 T3591 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@13d73476 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1022826 T3590 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1022827 T3565 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
   [junit4]   2> 1022828 T3565 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1022827 T3594 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52968/lx_/h collection:control_collection shard:shard1
   [junit4]   2> 1022829 T3594 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1022831 T3565 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1022833 T3596 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ead18c9 name:ZooKeeperConnection Watcher:127.0.0.1:22476/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1022833 T3565 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1022852 T3565 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1022853 T3594 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1022854 T3565 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 1022855 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1022856 T3594 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1022856 T3594 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C1529 name=collection1 org.apache.solr.core.SolrCore@2454f825 url=http://127.0.0.1:52968/lx_/h/collection1 node=127.0.0.1:52968_lx_%2Fh C1529_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:52968/lx_/h, core=collection1, node_name=127.0.0.1:52968_lx_%2Fh}
   [junit4]   2> 1022856 T3594 C1529 P52968 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52968/lx_/h/collection1/
   [junit4]   2> 1022856 T3588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1022856 T3594 C1529 P52968 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1022857 T3594 C1529 P52968 oasc.SyncStrategy.syncToMe http://127.0.0.1:52968/lx_/h/collection1/ has no replicas
   [junit4]   2> 1022857 T3594 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52968/lx_/h/collection1/ shard1
   [junit4]   2> 1022857 T3594 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 1022867 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1022868 T3587 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1022868 T3596 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1022878 T3588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1022881 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1022984 T3587 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1022984 T3596 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1023031 T3594 oasc.ZkController.register We are http://127.0.0.1:52968/lx_/h/collection1/ and leader is http://127.0.0.1:52968/lx_/h/collection1/
   [junit4]   2> 1023031 T3594 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52968/lx_/h
   [junit4]   2> 1023031 T3594 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1023032 T3594 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1023032 T3594 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1023033 T3565 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1023034 T3594 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1023033 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1023035 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1023035 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1023036 T3588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1023036 T3565 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:65427
   [junit4]   2> 1023037 T3588 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52968/lx_/h",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52968_lx_%2Fh",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1023037 T3565 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1023038 T3565 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1023038 T3565 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1387763303758
   [junit4]   2> 1023039 T3565 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1387763303758/'
   [junit4]   2> 1023039 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1023065 T3565 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1387763303758/solr.xml
   [junit4]   2> 1023118 T3565 oasc.CoreContainer.<init> New CoreContainer 1533965637
   [junit4]   2> 1023119 T3565 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1387763303758/]
   [junit4]   2> 1023120 T3565 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1023120 T3565 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1023121 T3565 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1023121 T3565 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1023122 T3565 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1023122 T3565 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1023122 T3565 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1023123 T3565 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1023123 T3565 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1023135 T3565 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1023135 T3565 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1023136 T3565 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1023136 T3565 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:22476/solr
   [junit4]   2> 1023137 T3565 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1023137 T3565 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1023139 T3607 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@30d533e8 name:ZooKeeperConnection Watcher:127.0.0.1:22476 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1023140 T3565 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1023142 T3596 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1023142 T3587 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1023152 T3565 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1023154 T3609 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ebc7e86 name:ZooKeeperConnection Watcher:127.0.0.1:22476/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1023154 T3565 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1023166 T3565 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1024169 T3565 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:65427_lx_%2Fh
   [junit4]   2> 1024171 T3565 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:65427_lx_%2Fh
   [junit4]   2> 1024175 T3596 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1024176 T3609 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1024176 T3587 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1024192 T3610 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1024193 T3610 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1024194 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024194 T3610 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1024194 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024195 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024196 T3588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1024197 T3588 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:65427/lx_/h",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:65427_lx_%2Fh",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1024197 T3588 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 1024197 T3588 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1024201 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1024305 T3587 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1024305 T3609 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1024305 T3596 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1025196 T3610 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1025196 T3610 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1387763303758/collection1
   [junit4]   2> 1025196 T3610 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1025197 T3610 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1025198 T3610 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1025198 T3610 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1387763303758/collection1/'
   [junit4]   2> 1025200 T3610 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1387763303758/collection1/lib/classes/' to classloader
   [junit4]   2> 1025201 T3610 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1387763303758/collection1/lib/README' to classloader
   [junit4]   2> 1025266 T3610 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 1025330 T3610 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1025431 T3610 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1025442 T3610 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1026089 T3610 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1026091 T3610 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1026092 T3610 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1026105 T3610 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1026110 T3610 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1026122 T3610 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1026127 T3610 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1026132 T3610 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1026132 T3610 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1026133 T3610 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1026133 T3610 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1026134 T3610 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1026134 T3610 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1026135 T3610 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1026135 T3610 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1387763303758/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1387763300900/jetty1/
   [junit4]   2> 1026136 T3610 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@c569c60
   [junit4]   2> 1026137 T3610 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1387763300900/jetty1
   [junit4]   2> 1026137 T3610 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1387763300900/jetty1/index/
   [junit4]   2> 1026137 T3610 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1387763300900/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 1026138 T3610 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1387763300900/jetty1/index
   [junit4]   2> 1026138 T3610 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=75.169921875, floorSegmentMB=1.41015625, forceMergeDeletesPctAllowed=7.465621445085295, segmentsPerTier=33.0, maxCFSSegmentSizeMB=0.6943359375, noCFSRatio=0.49578037389320406
   [junit4]   2> 1026139 T3610 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4e3895c7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5c90c16d; maxCacheMB=0.5947265625 maxMergeSizeMB=0.3359375))),segFN=segments_1,generation=1}
   [junit4]   2> 1026140 T3610 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1026143 T3610 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1026143 T3610 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1026144 T3610 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1026144 T3610 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1026144 T3610 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1026145 T3610 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1026145 T3610 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1026146 T3610 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1026146 T3610 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1026147 T3610 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1026147 T3610 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1026148 T3610 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1026148 T3610 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1026149 T3610 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1026149 T3610 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1026150 T3610 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1026160 T3610 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1026165 T3610 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1026165 T3610 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1026166 T3610 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=19, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1026167 T3610 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4e3895c7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5c90c16d; maxCacheMB=0.5947265625 maxMergeSizeMB=0.3359375))),segFN=segments_1,generation=1}
   [junit4]   2> 1026167 T3610 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1026168 T3610 oass.SolrIndexSearcher.<init> Opening Searcher@45fab5e5 main
   [junit4]   2> 1026171 T3611 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@45fab5e5 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1026173 T3610 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1026174 T3565 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
   [junit4]   2> 1026175 T3565 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1026174 T3614 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:65427/lx_/h collection:collection1 shard:shard1
   [junit4]   2> 1026176 T3614 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1026220 T3614 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1026222 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1026223 T3614 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1026223 T3614 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1026223 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> ASYNC  NEW_CORE C1530 name=collection1 org.apache.solr.core.SolrCore@6d2134e4 url=http://127.0.0.1:65427/lx_/h/collection1 node=127.0.0.1:65427_lx_%2Fh C1530_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:65427/lx_/h, core=collection1, node_name=127.0.0.1:65427_lx_%2Fh}
   [junit4]   2> 1026223 T3614 C1530 P65427 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:65427/lx_/h/collection1/
   [junit4]   2> 1026224 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1026224 T3614 C1530 P65427 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1026225 T3614 C1530 P65427 oasc.SyncStrategy.syncToMe http://127.0.0.1:65427/lx_/h/collection1/ has no replicas
   [junit4]   2> 1026225 T3614 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:65427/lx_/h/collection1/ shard1
   [junit4]   2> 1026225 T3614 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1026225 T3588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1026243 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1026245 T3587 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1026246 T3596 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1026246 T3609 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1026257 T3588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1026261 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1026367 T3587 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1026367 T3609 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1026367 T3596 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1026408 T3614 oasc.ZkController.register We are http://127.0.0.1:65427/lx_/h/collection1/ and leader is http://127.0.0.1:65427/lx_/h/collection1/
   [junit4]   2> 1026408 T3614 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:65427/lx_/h
   [junit4]   2> 1026408 T3614 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1026408 T3614 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1026409 T3614 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1026410 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1026411 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1026411 T3614 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1026411 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1026412 T3588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1026412 T3588 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:65427/lx_/h",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:65427_lx_%2Fh",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1026424 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1026450 T3565 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1026453 T3565 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:30267
   [junit4]   2> 1026454 T3565 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1026455 T3565 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1026455 T3565 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1387763307080
   [junit4]   2> 1026456 T3565 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1387763307080/'
   [junit4]   2> 1026495 T3565 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1387763307080/solr.xml
   [junit4]   2> 1026535 T3587 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1026535 T3596 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1026535 T3609 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1026585 T3565 oasc.CoreContainer.<init> New CoreContainer 217455702
   [junit4]   2> 1026585 T3565 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1387763307080/]
   [junit4]   2> 1026588 T3565 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1026588 T3565 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1026589 T3565 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1026589 T3565 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1026590 T3565 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1026590 T3565 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1026591 T3565 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1026591 T3565 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1026592 T3565 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1026610 T3565 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1026611 T3565 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1026611 T3565 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1026612 T3565 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:22476/solr
   [junit4]   2> 1026613 T3565 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1026614 T3565 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1026616 T3625 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71be58bf name:ZooKeeperConnection Watcher:127.0.0.1:22476 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1026618 T3565 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1026622 T3565 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1026624 T3627 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@68bf0bb1 name:ZooKeeperConnection Watcher:127.0.0.1:22476/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1026624 T3565 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1026634 T3565 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1027637 T3565 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:30267_lx_%2Fh
   [junit4]   2> 1027643 T3565 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:30267_lx_%2Fh
   [junit4]   2> 1027647 T3596 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1027648 T3627 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1027647 T3609 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1027647 T3587 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1027656 T3628 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1027656 T3628 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1027658 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1027658 T3628 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1027658 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1027659 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1027660 T3588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1027660 T3588 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:30267/lx_/h",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:30267_lx_%2Fh",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1027660 T3588 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 1027661 T3588 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1027663 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1027766 T3627 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1027766 T3609 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1027766 T3587 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1027766 T3596 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1028659 T3628 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1028659 T3628 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1387763307080/collection1
   [junit4]   2> 1028660 T3628 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1028660 T3628 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1028661 T3628 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1028662 T3628 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1387763307080/collection1/'
   [junit4]   2> 1028664 T3628 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1387763307080/collection1/lib/README' to classloader
   [junit4]   2> 1028664 T3628 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1387763307080/collection1/lib/classes/' to classloader
   [junit4]   2> 1028731 T3628 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 1028794 T3628 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1028896 T3628 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1028907 T3628 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1029553 T3628 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1029554 T3628 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1029555 T3628 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1029568 T3628 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1029572 T3628 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1029584 T3628 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1029589 T3628 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1029594 T3628 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1029595 T3628 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1029595 T3628 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1029595 T3628 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1029596 T3628 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1029597 T3628 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1029597 T3628 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1029597 T3628 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1387763307080/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1387763300900/jetty2/
   [junit4]   2> 1029598 T3628 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@c569c60
   [junit4]   2> 1029599 T3628 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1387763300900/jetty2
   [junit4]   2> 1029599 T3628 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1387763300900/jetty2/index/
   [junit4]   2> 1029599 T3628 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1387763300900/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 1029600 T3628 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1387763300900/jetty2/index
   [junit4]   2> 1029600 T3628 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=75.169921875, floorSegmentMB=1.41015625, forceMergeDeletesPctAllowed=7.465621445085295, segmentsPerTier=33.0, maxCFSSegmentSizeMB=0.6943359375, noCFSRatio=0.49578037389320406
   [junit4]   2> 1029601 T3628 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@66fc9fec lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@65a51f28; maxCacheMB=0.5947265625 maxMergeSizeMB=0.3359375))),segFN=segments_1,generation=1}
   [junit4]   2> 1029602 T3628 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1029605 T3628 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1029605 T3628 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1029606 T3628 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1029606 T3628 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1029606 T3628 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1029607 T3628 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1029607 T3628 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1029608 T3628 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1029608 T3628 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1029609 T3628 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1029609 T3628 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1029610 T3628 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1029610 T3628 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1029611 T3628 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1029611 T3628 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1029612 T3628 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1029622 T3628 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1029627 T3628 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1029627 T3628 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1029628 T3628 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=19, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1029629 T3628 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@66fc9fec lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@65a51f28; maxCacheMB=0.5947265625 maxMergeSizeMB=0.3359375))),segFN=segments_1,generation=1}
   [junit4]   2> 1029629 T3628 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1029630 T3628 oass.SolrIndexSearcher.<init> Opening Searcher@2e3dc3e7 main
   [junit4]   2> 1029634 T3629 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2e3dc3e7 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1029636 T3628 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1029637 T3565 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
   [junit4]   2> 1029638 T3565 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1029637 T3632 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:30267/lx_/h collection:collection1 shard:shard2
   [junit4]   2> 1029639 T3632 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 1029660 T3632 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 1029663 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1029663 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1029663 T3632 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1029663 T3632 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1029663 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> ASYNC  NEW_CORE C1531 name=collection1 org.apache.solr.core.SolrCore@2e776824 url=http://127.0.0.1:30267/lx_/h/collection1 node=127.0.0.1:30267_lx_%2Fh C1531_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:30267/lx_/h, core=collection1, node_name=127.0.0.1:30267_lx_%2Fh}
   [junit4]   2> 1029664 T3632 C1531 P30267 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:30267/lx_/h/collection1/
   [junit4]   2> 1029664 T3588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1029664 T3632 C1531 P30267 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1029665 T3632 C1531 P30267 oasc.SyncStrategy.syncToMe http://127.0.0.1:30267/lx_/h/collection1/ has no replicas
   [junit4]   2> 1029665 T3632 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:30267/lx_/h/collection1/ shard2
   [junit4]   2> 1029666 T3632 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 1029667 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1029668 T3627 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1029668 T3587 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1029668 T3596 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1029668 T3609 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1029680 T3588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1029689 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1029791 T3627 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1029791 T3596 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1029791 T3587 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1029791 T3609 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1029833 T3632 oasc.ZkController.register We are http://127.0.0.1:30267/lx_/h/collection1/ and leader is http://127.0.0.1:30267/lx_/h/collection1/
   [junit4]   2> 1029833 T3632 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:30267/lx_/h
   [junit4]   2> 1029833 T3632 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1029833 T3632 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1029834 T3632 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1029835 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1029835 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1029835 T3632 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1029836 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1029837 T3588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1029838 T3588 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:30267/lx_/h",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:30267_lx_%2Fh",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 1029840 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1029911 T3565 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1029916 T3565 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:26540
   [junit4]   2> 1029917 T3565 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1029917 T3565 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1029918 T3565 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1387763310542
   [junit4]   2> 1029918 T3565 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1387763310542/'
   [junit4]   2> 1029942 T3609 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1029942 T3596 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1029942 T3587 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1029942 T3627 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1029955 T3565 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1387763310542/solr.xml
   [junit4]   2> 1030030 T3565 oasc.CoreContainer.<init> New CoreContainer 712003828
   [junit4]   2> 1030031 T3565 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1387763310542/]
   [junit4]   2> 1030033 T3565 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1030033 T3565 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1030034 T3565 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1030034 T3565 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1030035 T3565 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1030035 T3565 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1030036 T3565 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1030036 T3565 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1030037 T3565 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1030054 T3565 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1030054 T3565 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1030055 T3565 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1030055 T3565 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:22476/solr
   [junit4]   2> 1030056 T3565 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1030057 T3565 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1030059 T3643 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@33d2d8f0 name:ZooKeeperConnection Watcher:127.0.0.1:22476 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1030060 T3565 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1030064 T3565 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1030071 T3645 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e7f2b91 name:ZooKeeperConnection Watcher:127.0.0.1:22476/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1030072 T3565 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1030076 T3565 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1031079 T3565 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:26540_lx_%2Fh
   [junit4]   2> 1031087 T3565 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:26540_lx_%2Fh
   [junit4]   2> 1031091 T3627 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1031092 T3645 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1031092 T3596 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1031092 T3587 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1031091 T3609 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1031115 T3646 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1031116 T3646 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1031117 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1031117 T3646 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1031118 T3587 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1031118 T358

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

loud.BasicDistributedZk2Test-1387763300900/jetty3 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1387763300900/jetty3;done=false>>]
   [junit4]   2> 1094937 T3645 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1387763300900/jetty3
   [junit4]   2> 1094938 T3645 oasc.LeaderElector$1.process WARN  java.lang.RuntimeException: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer
   [junit4]   2> 	at org.apache.solr.cloud.Overseer.createOverseerNode(Overseer.java:1054)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer.getInQueue(Overseer.java:1027)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:157)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:385)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:178)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:385)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:249)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$9.execute(SolrZkClient.java:304)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$9.execute(SolrZkClient.java:301)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:301)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer.createOverseerNode(Overseer.java:1045)
   [junit4]   2> 	... 18 more
   [junit4]   2> 
   [junit4]   2> 1094939 T3645 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1094939 T3645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1094939 T3645 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1094939 T3645 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:252)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:249)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:249)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 75679 T3564 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> 1096013 T3664 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Lucene46: {foo_b=PostingsFormat(name=Asserting), n_f1=Pulsing41(freqCutoff=15 minBlockSize=2 maxBlockSize=66), foo_d=MockFixedIntBlock(blockSize=886), foo_f=PostingsFormat(name=Asserting), n_tl1=Pulsing41(freqCutoff=15 minBlockSize=2 maxBlockSize=66), n_d1=PostingsFormat(name=Direct), rnd_b=MockFixedIntBlock(blockSize=886), intDefault=Pulsing41(freqCutoff=15 minBlockSize=2 maxBlockSize=66), n_td1=Pulsing41(freqCutoff=15 minBlockSize=2 maxBlockSize=66), timestamp=PostingsFormat(name=Direct), id=MockFixedIntBlock(blockSize=886), range_facet_sl=MockFixedIntBlock(blockSize=886), range_facet_si=PostingsFormat(name=Direct), oddField_s=MockFixedIntBlock(blockSize=886), multiDefault=PostingsFormat(name=Direct), n_tf1=PostingsFormat(name=Direct), n_dt1=Pulsing41(freqCutoff=15 minBlockSize=2 maxBlockSize=66), range_facet_l=PostingsFormat(name=Direct), n_ti1=MockFixedIntBlock(blockSize=886), text=PostingsFormat(name=Asserting), _version_=Pulsing41(freqCutoff=15 minBlockSize=2 maxBlockSize=66), SubjectTerms_mfacet=Pulsing41(freqCutoff=15 minBlockSize=2 maxBlockSize=66), a_t=PostingsFormat(name=Direct), n_tdt1=Pulsing41(freqCutoff=15 minBlockSize=2 maxBlockSize=66), other_tl1=Pulsing41(freqCutoff=15 minBlockSize=2 maxBlockSize=66), n_l1=PostingsFormat(name=Direct), a_si=Pulsing41(freqCutoff=15 minBlockSize=2 maxBlockSize=66)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=de_DE, timezone=EAT
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=1,free=33762144,total=513933312
   [junit4]   2> NOTE: All tests run in this JVM: [TestJmxIntegration, DirectSolrConnectionTest, SolrCoreCheckLockOnStartupTest, PingRequestHandlerTest, DefaultValueUpdateProcessorTest, DebugComponentTest, HardAutoCommitTest, SpellCheckCollatorTest, FullSolrCloudDistribCmdsTest, TestIndexSearcher, TestCSVResponseWriter, BadIndexSchemaTest, HdfsBasicDistributedZkTest, TestCollationField, TestZkChroot, HighlighterTest, TestSolrCoreProperties, SpellCheckComponentTest, TestQuerySenderListener, HdfsDirectoryTest, TestFastOutputStream, TestManagedSchemaFieldResource, DistanceFunctionTest, TestCloudManagedSchemaAddField, DateFieldTest, TestStressLucene, DirectSolrSpellCheckerTest, HdfsChaosMonkeySafeLeaderTest, TestReload, CurrencyFieldOpenExchangeTest, TestRangeQuery, SuggestComponentTest, LeaderElectionIntegrationTest, IndexSchemaRuntimeFieldTest, TestIndexingPerformance, TestImplicitCoreProperties, ChaosMonkeySafeLeaderTest, EnumFieldTest, TestFieldResource, TestUpdate, TestStressReorder, BlockCacheTest, CurrencyFieldXmlFileTest, TestCollationKeyRangeQueries, TestSimpleQParserPlugin, TestMaxScoreQueryParser, CoreMergeIndexesAdminHandlerTest, TestDFRSimilarityFactory, TestAnalyzedSuggestions, CollectionsAPIDistributedZkTest, StatsComponentTest, MigrateRouteKeyTest, MinimalSchemaTest, BasicDistributedZk2Test]
   [junit4] Completed on J1 in 76.23s, 1 test, 1 error <<< FAILURES!

[...truncated 736 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:466: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:439: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/common-build.xml:491: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:1307: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:940: There were test failures: 347 suites, 1517 tests, 1 error, 32 ignored (4 assumptions)

Total time: 123 minutes 35 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure

UILD\\s+FAILED(?s:.*+)                                                                                                                                   \
)"}

Mime
View raw message