You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/11/24 04:21:10 UTC

[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.6.0) - Build # 1027 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/1027/
Java: 64bit/jdk1.6.0 -XX:+UseCompressedOops -XX:+UseParallelGC

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

Error Message:
Wrong doc count on shard1_0 expected:<100> but was:<63>

Stack Trace:
java.lang.AssertionError: Wrong doc count on shard1_0 expected:<100> but was:<63>
	at __randomizedtesting.SeedInfo.seed([C56395B842EEDBAC:44851BA035B1BB90]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.failNotEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:128)
	at org.junit.Assert.assertEquals(Assert.java:472)
	at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:477)
	at org.apache.solr.cloud.ShardSplitTest.splitByUniqueKeyTest(ShardSplitTest.java:249)
	at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:113)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	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:695)




Build Log:
[...truncated 9622 lines...]
   [junit4] Suite: org.apache.solr.cloud.ShardSplitTest
   [junit4]   2> 944885 T3276 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_r/qs
   [junit4]   2> 944889 T3276 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1385261211257
   [junit4]   2> 944891 T3276 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 944891 T3277 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 944992 T3276 oasc.ZkTestServer.run start zk server on port:53512
   [junit4]   2> 944994 T3276 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 945002 T3283 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@54df8263 name:ZooKeeperConnection Watcher:127.0.0.1:53512 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 945002 T3276 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 945002 T3276 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 945021 T3276 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 945025 T3285 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@47f0bdcb name:ZooKeeperConnection Watcher:127.0.0.1:53512/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 945025 T3276 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 945026 T3276 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 945036 T3276 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 945044 T3276 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 945051 T3276 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 945059 T3276 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 945059 T3276 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 945072 T3276 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 945073 T3276 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 945082 T3276 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 945083 T3276 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 945092 T3276 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 945093 T3276 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 945102 T3276 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 945102 T3276 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 945112 T3276 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 945112 T3276 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 945122 T3276 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 945123 T3276 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 945132 T3276 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 945132 T3276 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 945141 T3276 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 945141 T3276 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 945151 T3276 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 945151 T3276 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 945160 T3276 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 945161 T3276 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 945483 T3276 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 945508 T3276 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53515
   [junit4]   2> 945513 T3276 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 945513 T3276 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 945514 T3276 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-controljetty-1385261211539
   [junit4]   2> 945514 T3276 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-controljetty-1385261211539/'
   [junit4]   2> 945540 T3276 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1385261211539/solr.xml
   [junit4]   2> 945583 T3276 oasc.CoreContainer.<init> New CoreContainer 581817677
   [junit4]   2> 945583 T3276 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-controljetty-1385261211539/]
   [junit4]   2> 945584 T3276 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 945585 T3276 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 945585 T3276 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 945585 T3276 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 945586 T3276 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 945586 T3276 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 945587 T3276 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 945587 T3276 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 945587 T3276 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 945591 T3276 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 945591 T3276 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 945592 T3276 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 945592 T3276 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53512/solr
   [junit4]   2> 945592 T3276 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 945594 T3276 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 945598 T3296 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@428ec404 name:ZooKeeperConnection Watcher:127.0.0.1:53512 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 945599 T3276 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 945607 T3276 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 945611 T3298 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2bda3c13 name:ZooKeeperConnection Watcher:127.0.0.1:53512/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 945611 T3276 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 945615 T3276 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 945627 T3276 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 945637 T3276 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 945643 T3276 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53515__r%2Fqs
   [junit4]   2> 945645 T3276 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53515__r%2Fqs
   [junit4]   2> 945657 T3276 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 945673 T3276 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 945680 T3276 oasc.Overseer.start Overseer (id=90784478741528579-127.0.0.1:53515__r%2Fqs-n_0000000000) starting
   [junit4]   2> 945692 T3276 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 945710 T3300 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 945712 T3276 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 945724 T3276 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 945730 T3276 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 945744 T3299 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 945747 T3301 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 945748 T3301 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 945750 T3301 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 945750 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 945754 T3299 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 945755 T3299 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:53515/_r/qs",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53515__r%2Fqs",
   [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> 945755 T3299 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 945755 T3299 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 945761 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 945764 T3298 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> 946752 T3301 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 946752 T3301 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-controljetty-1385261211539/collection1
   [junit4]   2> 946752 T3301 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 946754 T3301 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 946754 T3301 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 946758 T3301 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-controljetty-1385261211539/collection1/'
   [junit4]   2> 946759 T3301 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1385261211539/collection1/lib/classes/' to classloader
   [junit4]   2> 946759 T3301 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1385261211539/collection1/lib/README' to classloader
   [junit4]   2> 946804 T3301 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 946834 T3301 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 946838 T3301 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 946844 T3301 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 947139 T3301 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 947141 T3301 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 947143 T3301 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 947149 T3301 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 947224 T3301 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 947225 T3301 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-controljetty-1385261211539/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1385261211257/control/data/
   [junit4]   2> 947225 T3301 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b3e02ed
   [junit4]   2> 947226 T3301 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1385261211257/control/data
   [junit4]   2> 947226 T3301 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1385261211257/control/data/index/
   [junit4]   2> 947226 T3301 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1385261211257/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 947227 T3301 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1385261211257/control/data/index
   [junit4]   2> 947227 T3301 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=2.7333984375, floorSegmentMB=1.54296875, forceMergeDeletesPctAllowed=12.038894970024476, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1179541042105881
   [junit4]   2> 947228 T3301 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2048d02f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5395fbac),segFN=segments_1,generation=1}
   [junit4]   2> 947229 T3301 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 947232 T3301 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 947232 T3301 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 947232 T3301 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 947232 T3301 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 947233 T3301 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 947233 T3301 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 947233 T3301 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 947234 T3301 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 947234 T3301 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 947235 T3301 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 947235 T3301 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 947235 T3301 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 947235 T3301 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 947236 T3301 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 947236 T3301 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 947237 T3301 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 947242 T3301 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 947246 T3301 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 947246 T3301 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 947247 T3301 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1056194770, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 947248 T3301 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2048d02f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5395fbac),segFN=segments_1,generation=1}
   [junit4]   2> 947248 T3301 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 947248 T3301 oass.SolrIndexSearcher.<init> Opening Searcher@4f7c26b4 main
   [junit4]   2> 947253 T3302 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4f7c26b4 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 947255 T3301 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 947255 T3301 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53515/_r/qs collection:control_collection shard:shard1
   [junit4]   2> 947258 T3301 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 947281 T3301 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 947287 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 947289 T3301 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 947290 T3301 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C714 name=collection1 org.apache.solr.core.SolrCore@6eafcd05 url=http://127.0.0.1:53515/_r/qs/collection1 node=127.0.0.1:53515__r%2Fqs C714_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:53515/_r/qs, core=collection1, node_name=127.0.0.1:53515__r%2Fqs}
   [junit4]   2> 947290 T3301 C714 P53515 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53515/_r/qs/collection1/
   [junit4]   2> 947290 T3301 C714 P53515 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 947291 T3301 C714 P53515 oasc.SyncStrategy.syncToMe http://127.0.0.1:53515/_r/qs/collection1/ has no replicas
   [junit4]   2> 947291 T3301 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53515/_r/qs/collection1/ shard1
   [junit4]   2> 947291 T3301 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 947292 T3299 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 947303 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 947306 T3298 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> 947320 T3299 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 947329 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 947439 T3298 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> 947470 T3301 oasc.ZkController.register We are http://127.0.0.1:53515/_r/qs/collection1/ and leader is http://127.0.0.1:53515/_r/qs/collection1/
   [junit4]   2> 947471 T3301 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53515/_r/qs
   [junit4]   2> 947471 T3301 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 947471 T3301 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 947472 T3301 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 947474 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 947474 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 947474 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 947477 T3301 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 947480 T3276 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 947480 T3276 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 947481 T3299 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 947483 T3299 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53515/_r/qs",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53515__r%2Fqs",
   [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":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 947484 T3276 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 947487 T3305 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2147f84a name:ZooKeeperConnection Watcher:127.0.0.1:53512/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 947487 T3276 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 947493 T3276 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 947495 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 947504 T3276 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 947606 T3305 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> 947607 T3298 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> 947778 T3276 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 947782 T3276 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53519
   [junit4]   2> 947785 T3276 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 947785 T3276 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 947786 T3276 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1385261213871
   [junit4]   2> 947786 T3276 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1385261213871/'
   [junit4]   2> 947811 T3276 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1385261213871/solr.xml
   [junit4]   2> 947846 T3276 oasc.CoreContainer.<init> New CoreContainer 576239103
   [junit4]   2> 947846 T3276 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1385261213871/]
   [junit4]   2> 947848 T3276 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 947848 T3276 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 947849 T3276 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 947849 T3276 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 947850 T3276 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 947850 T3276 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 947850 T3276 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 947851 T3276 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 947851 T3276 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 947855 T3276 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 947855 T3276 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 947855 T3276 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 947856 T3276 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53512/solr
   [junit4]   2> 947856 T3276 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 947857 T3276 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 947862 T3316 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e1489f6 name:ZooKeeperConnection Watcher:127.0.0.1:53512 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 947863 T3276 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 947869 T3276 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 947874 T3318 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2218c2e5 name:ZooKeeperConnection Watcher:127.0.0.1:53512/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 947874 T3276 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 947887 T3276 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 948899 T3276 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53519__r%2Fqs
   [junit4]   2> 948902 T3276 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53519__r%2Fqs
   [junit4]   2> 948917 T3305 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 948917 T3298 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 948917 T3318 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 948933 T3319 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 948933 T3319 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 948936 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 948936 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 948936 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 948936 T3319 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 948942 T3299 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 948944 T3299 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:53519/_r/qs",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53519__r%2Fqs",
   [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> 948944 T3299 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 948945 T3299 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 948952 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 949060 T3305 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> 949061 T3298 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> 949061 T3318 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> 949938 T3319 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 949938 T3319 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1385261213871/collection1
   [junit4]   2> 949938 T3319 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 949941 T3319 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 949941 T3319 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 949944 T3319 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1385261213871/collection1/'
   [junit4]   2> 949945 T3319 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1385261213871/collection1/lib/classes/' to classloader
   [junit4]   2> 949946 T3319 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1385261213871/collection1/lib/README' to classloader
   [junit4]   2> 949992 T3319 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 950023 T3319 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 950027 T3319 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 950035 T3319 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 950331 T3319 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 950334 T3319 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 950334 T3319 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 950341 T3319 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 950416 T3319 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 950416 T3319 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1385261213871/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty1/
   [junit4]   2> 950416 T3319 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b3e02ed
   [junit4]   2> 950417 T3319 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty1
   [junit4]   2> 950417 T3319 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty1/index/
   [junit4]   2> 950418 T3319 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 950418 T3319 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty1/index
   [junit4]   2> 950418 T3319 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=2.7333984375, floorSegmentMB=1.54296875, forceMergeDeletesPctAllowed=12.038894970024476, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1179541042105881
   [junit4]   2> 950419 T3319 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@20f796ee lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@851d76f),segFN=segments_1,generation=1}
   [junit4]   2> 950420 T3319 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 950424 T3319 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 950424 T3319 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 950424 T3319 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 950425 T3319 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 950425 T3319 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 950425 T3319 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 950426 T3319 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 950426 T3319 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 950426 T3319 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 950427 T3319 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 950427 T3319 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 950427 T3319 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 950428 T3319 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 950428 T3319 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 950429 T3319 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 950429 T3319 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 950434 T3319 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 950438 T3319 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 950438 T3319 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 950440 T3319 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1056194770, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 950440 T3319 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@20f796ee lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@851d76f),segFN=segments_1,generation=1}
   [junit4]   2> 950441 T3319 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 950442 T3319 oass.SolrIndexSearcher.<init> Opening Searcher@6676e2b9 main
   [junit4]   2> 950448 T3320 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6676e2b9 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 950450 T3319 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 950451 T3319 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53519/_r/qs collection:collection1 shard:shard1
   [junit4]   2> 950453 T3319 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 950476 T3319 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 950482 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 950482 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 950483 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 950484 T3319 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 950484 T3319 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C715 name=collection1 org.apache.solr.core.SolrCore@d4a2562 url=http://127.0.0.1:53519/_r/qs/collection1 node=127.0.0.1:53519__r%2Fqs C715_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:53519/_r/qs, core=collection1, node_name=127.0.0.1:53519__r%2Fqs}
   [junit4]   2> 950485 T3319 C715 P53519 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53519/_r/qs/collection1/
   [junit4]   2> 950485 T3319 C715 P53519 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 950485 T3319 C715 P53519 oasc.SyncStrategy.syncToMe http://127.0.0.1:53519/_r/qs/collection1/ has no replicas
   [junit4]   2> 950485 T3319 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53519/_r/qs/collection1/ shard1
   [junit4]   2> 950486 T3319 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 950490 T3299 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 950504 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 950512 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 950525 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 950633 T3305 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> 950633 T3298 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> 950634 T3318 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> 950668 T3319 oasc.ZkController.register We are http://127.0.0.1:53519/_r/qs/collection1/ and leader is http://127.0.0.1:53519/_r/qs/collection1/
   [junit4]   2> 950669 T3319 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53519/_r/qs
   [junit4]   2> 950669 T3319 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 950669 T3319 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 950669 T3319 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 950672 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 950672 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 950672 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 950675 T3319 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 950679 T3299 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 950679 T3276 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 950680 T3276 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 950681 T3299 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:53519/_r/qs",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53519__r%2Fqs",
   [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> 950688 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 950797 T3305 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> 950798 T3318 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> 950798 T3298 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> 950961 T3276 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 950966 T3276 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53522
   [junit4]   2> 950968 T3276 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 950968 T3276 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 950969 T3276 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1385261217049
   [junit4]   2> 950969 T3276 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1385261217049/'
   [junit4]   2> 950996 T3276 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1385261217049/solr.xml
   [junit4]   2> 951044 T3276 oasc.CoreContainer.<init> New CoreContainer 2022936998
   [junit4]   2> 951045 T3276 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1385261217049/]
   [junit4]   2> 951045 T3276 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 951046 T3276 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 951046 T3276 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 951046 T3276 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 951047 T3276 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 951047 T3276 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 951047 T3276 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 951048 T3276 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 951049 T3276 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 951052 T3276 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 951053 T3276 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 951053 T3276 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 951053 T3276 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53512/solr
   [junit4]   2> 951054 T3276 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 951055 T3276 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 951060 T3332 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@203f6722 name:ZooKeeperConnection Watcher:127.0.0.1:53512 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 951061 T3276 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 951071 T3276 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 951075 T3334 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@40a88a21 name:ZooKeeperConnection Watcher:127.0.0.1:53512/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 951075 T3276 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 951089 T3276 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 952104 T3276 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53522__r%2Fqs
   [junit4]   2> 952107 T3276 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53522__r%2Fqs
   [junit4]   2> 952120 T3298 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 952120 T3305 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 952121 T3318 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 952123 T3334 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 952138 T3335 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 952139 T3335 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 952141 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 952141 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 952141 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 952141 T3335 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 952147 T3299 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 952149 T3299 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:53522/_r/qs",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53522__r%2Fqs",
   [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> 952149 T3299 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 952149 T3299 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 952157 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 952264 T3298 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> 952265 T3318 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> 952265 T3305 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> 952266 T3334 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> 953143 T3335 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 953143 T3335 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1385261217049/collection1
   [junit4]   2> 953144 T3335 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 953146 T3335 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 953146 T3335 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 953149 T3335 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1385261217049/collection1/'
   [junit4]   2> 953150 T3335 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1385261217049/collection1/lib/classes/' to classloader
   [junit4]   2> 953151 T3335 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1385261217049/collection1/lib/README' to classloader
   [junit4]   2> 953194 T3335 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 953224 T3335 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 953228 T3335 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 953235 T3335 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 953548 T3335 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 953550 T3335 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 953551 T3335 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 953558 T3335 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 953631 T3335 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 953632 T3335 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1385261217049/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty2/
   [junit4]   2> 953632 T3335 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b3e02ed
   [junit4]   2> 953633 T3335 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty2
   [junit4]   2> 953633 T3335 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty2/index/
   [junit4]   2> 953633 T3335 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 953634 T3335 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty2/index
   [junit4]   2> 953634 T3335 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=2.7333984375, floorSegmentMB=1.54296875, forceMergeDeletesPctAllowed=12.038894970024476, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1179541042105881
   [junit4]   2> 953635 T3335 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@6b9e94e8 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8a17663),segFN=segments_1,generation=1}
   [junit4]   2> 953635 T3335 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 953639 T3335 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 953639 T3335 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 953640 T3335 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 953641 T3335 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 953641 T3335 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 953641 T3335 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 953641 T3335 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 953642 T3335 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 953642 T3335 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 953642 T3335 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 953643 T3335 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 953643 T3335 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 953644 T3335 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 953644 T3335 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 953644 T3335 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 953645 T3335 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 953651 T3335 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 953655 T3335 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 953656 T3335 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 953656 T3335 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1056194770, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 953657 T3335 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@6b9e94e8 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8a17663),segFN=segments_1,generation=1}
   [junit4]   2> 953657 T3335 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 953658 T3335 oass.SolrIndexSearcher.<init> Opening Searcher@68608f02 main
   [junit4]   2> 953664 T3336 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@68608f02 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 953667 T3335 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 953667 T3335 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53522/_r/qs collection:collection1 shard:shard2
   [junit4]   2> 953670 T3335 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 953691 T3335 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 953698 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 953698 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 953698 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 953700 T3335 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 953701 T3335 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C716 name=collection1 org.apache.solr.core.SolrCore@1fc3910f url=http://127.0.0.1:53522/_r/qs/collection1 node=127.0.0.1:53522__r%2Fqs C716_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:53522/_r/qs, core=collection1, node_name=127.0.0.1:53522__r%2Fqs}
   [junit4]   2> 953701 T3335 C716 P53522 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53522/_r/qs/collection1/
   [junit4]   2> 953702 T3335 C716 P53522 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 953702 T3335 C716 P53522 oasc.SyncStrategy.syncToMe http://127.0.0.1:53522/_r/qs/collection1/ has no replicas
   [junit4]   2> 953702 T3335 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53522/_r/qs/collection1/ shard2
   [junit4]   2> 953702 T3335 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 953704 T3299 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 953719 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 953726 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 953737 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 953846 T3298 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> 953846 T3334 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> 953847 T3305 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> 953847 T3318 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> 953885 T3335 oasc.ZkController.register We are http://127.0.0.1:53522/_r/qs/collection1/ and leader is http://127.0.0.1:53522/_r/qs/collection1/
   [junit4]   2> 953885 T3335 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53522/_r/qs
   [junit4]   2> 953885 T3335 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 953886 T3335 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 953886 T3335 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 953889 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 953890 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 953890 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 953892 T3335 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 953895 T3276 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 953896 T3276 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 953897 T3299 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 953898 T3299 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:53522/_r/qs",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53522__r%2Fqs",
   [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> 953906 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 954013 T3305 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> 954013 T3334 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> 954014 T3318 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> 954018 T3298 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> 954199 T3276 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 954203 T3276 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53525
   [junit4]   2> 954205 T3276 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 954205 T3276 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 954206 T3276 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-jetty3-1385261220264
   [junit4]   2> 954206 T3276 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty3-1385261220264/'
   [junit4]   2> 954232 T3276 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1385261220264/solr.xml
   [junit4]   2> 954267 T3276 oasc.CoreContainer.<init> New CoreContainer 1987711382
   [junit4]   2> 954268 T3276 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-jetty3-1385261220264/]
   [junit4]   2> 954269 T3276 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 954269 T3276 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 954270 T3276 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 954270 T3276 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 954270 T3276 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 954271 T3276 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 954271 T3276 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 954271 T3276 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 954272 T3276 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 954275 T3276 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 954275 T3276 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 954276 T3276 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 954276 T3276 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53512/solr
   [junit4]   2> 954276 T3276 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 954278 T3276 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 954282 T3348 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4818cb9e name:ZooKeeperConnection Watcher:127.0.0.1:53512 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 954283 T3276 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 954291 T3276 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 954294 T3350 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4c2f6b7d name:ZooKeeperConnection Watcher:127.0.0.1:53512/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 954294 T3276 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 954307 T3276 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 955319 T3276 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53525__r%2Fqs
   [junit4]   2> 955322 T3276 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53525__r%2Fqs
   [junit4]   2> 955336 T3298 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 955337 T3318 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 955339 T3334 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 955341 T3305 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 955341 T3350 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 955356 T3351 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 955357 T3351 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 955359 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 955359 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 955359 T3351 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 955359 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 955364 T3299 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 955366 T3299 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:53525/_r/qs",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53525__r%2Fqs",
   [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> 955367 T3299 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 955367 T3299 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 955374 T3298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 955481 T3305 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 955482 T3334 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 955482 T3318 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 955482 T3298 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 955483 T3350 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 956362 T3351 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 956363 T3351 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-jetty3-1385261220264/collection1
   [junit4]   2> 956363 T3351 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 956365 T3351 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 956365 T3351 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 956369 T3351 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty3-1385261220264/collection1/'
   [junit4]   2> 956370 T3351 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1385261220264/collection1/lib/classes/' to classloader
   [junit4]   2> 956371 T3351 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1385261220264/collection1/lib/README' to classloader
   [junit4]   2> 956414 T3351 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 956445 T3351 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 956450 T3351 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 956456 T3351 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 956761 T3351 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 956763 T3351 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 956764 T3351 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 956771 T3351 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 956845 T3351 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 956845 T3351 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-jetty3-1385261220264/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty3/
   [junit4]   2> 956845 T3351 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b3e02ed
   [junit4]   2> 956846 T3351 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty3
   [junit4]   2> 956846 T3351 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty3/index/
   [junit4]   2> 956847 T3351 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 956847 T3351 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty3/index
   [junit4]   2> 956847 T3351 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=2.7333984375, floorSegmentMB=1.54296875, forceMergeDeletesPctAllowed=12.038894970024476, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1179541042105881
   [junit4]   2> 956848 T3351 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1a59af4f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d30c140),segFN=segments_1,generation=1}
   [junit4]   2> 956848 T3351 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 956853 T3351 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 956853 T3351 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 956854 T3351 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 956854 T3351 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 956854 T3351 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 956855 T3351 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 956855 T3351 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 956855 T3351 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 956856 T3351 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 956856 T3351 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 956857 T3351 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 956857 T3351 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 956857 T3351 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 956858 T3351 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 956858 T3351 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 956859 T3351 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 956864 T3351 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 956868 T3351 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 956868 T3351 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 956869 T3351 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1056194770, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483

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

ate Closing SolrCoreState
   [junit4]   2> 994332 T3276 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 994332 T3276 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 994335 T3276 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 994336 T3276 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 994336 T3276 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty4 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty4;done=false>>]
   [junit4]   2> 994336 T3276 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty4
   [junit4]   2> 994337 T3276 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty4/index;done=false>>]
   [junit4]   2> 994337 T3276 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-1385261211257/jetty4/index
   [junit4]   2> 994341 T3367 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 994343 T3400 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 994355 T3276 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/_r/qs,null}
   [junit4]   2> 994419 T3276 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
   [junit4]   2> 994422 T3276 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53512 53512
   [junit4]   2> 994672 T3400 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2169cde1 name:ZooKeeperConnection Watcher:127.0.0.1:53512/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
   [junit4]   2> 994672 T3276 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 53515
   [junit4]   2> 994672 T3400 oascc.ConnectionManager.process Client->ZooKeeper status change trigger but we are already closed
   [junit4]   2> !!!! WARNING: best effort to remove /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-1385261211257 FAILED !!!!!
   [junit4]   2> 994678 T3276 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
   [junit4]   2> 994678 T3276 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53512 53512
   [junit4]   1>    /solr/collections/control_collection (3)
   [junit4]   1>    DATA:
   [junit4]   1>        {"configName":"conf1"}
   [junit4]   1>     /solr/collections/control_collection/shards (0)
   [junit4]   1>     /solr/collections/control_collection/leader_elect (1)
   [junit4]   1>      /solr/collections/control_collection/leader_elect/shard1 (1)
   [junit4]   1>       /solr/collections/control_collection/leader_elect/shard1/election (1)
   [junit4]   1>        /solr/collections/control_collection/leader_elect/shard1/election/90784478741528579-core_node1-n_0000000000 (0)
   [junit4]   1>     /solr/collections/control_collection/leaders (1)
   [junit4]   1>      /solr/collections/control_collection/leaders/shard1 (0)
   [junit4]   1>      DATA:
   [junit4]   1>          {
   [junit4]   1>            "core":"collection1",
   [junit4]   1>            "node_name":"127.0.0.1:53515__r%2Fqs",
   [junit4]   1>            "base_url":"http://127.0.0.1:53515/_r/qs"}
   [junit4]   1>   /solr/overseer_elect (2)
   [junit4]   1>    /solr/overseer_elect/election (5)
   [junit4]   1>     /solr/overseer_elect/election/90784478741528588-127.0.0.1:53529__r%2Fqs-n_0000000004 (0)
   [junit4]   1>     /solr/overseer_elect/election/90784478741528586-127.0.0.1:53525__r%2Fqs-n_0000000003 (0)
   [junit4]   1>     /solr/overseer_elect/election/90784478741528582-127.0.0.1:53519__r%2Fqs-n_0000000001 (0)
   [junit4]   1>     /solr/overseer_elect/election/90784478741528579-127.0.0.1:53515__r%2Fqs-n_0000000000 (0)
   [junit4]   1>     /solr/overseer_elect/election/90784478741528584-127.0.0.1:53522__r%2Fqs-n_0000000002 (0)
   [junit4]   1>    /solr/overseer_elect/leader (0)
   [junit4]   1>    DATA:
   [junit4]   1>        {"id":"90784478741528579-127.0.0.1:53515__r%2Fqs-n_0000000000"}
   [junit4]   1>  /zookeeper (1)
   [junit4]   1>  DATA:
   [junit4]   1>      
   [junit4]   1> 
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=ShardSplitTest -Dtests.method=testDistribSearch -Dtests.seed=C56395B842EEDBAC -Dtests.slow=true -Dtests.locale=de_AT -Dtests.timezone=America/Grenada -Dtests.file.encoding=ISO-8859-1
   [junit4] FAILURE 49.8s | ShardSplitTest.testDistribSearch <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: Wrong doc count on shard1_0 expected:<100> but was:<63>
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([C56395B842EEDBAC:44851BA035B1BB90]:0)
   [junit4]    > 	at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:477)
   [junit4]    > 	at org.apache.solr.cloud.ShardSplitTest.splitByUniqueKeyTest(ShardSplitTest.java:249)
   [junit4]    > 	at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:113)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:695)
   [junit4]   2> 994695 T3276 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 49815 T3275 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
   [junit4]   2> 994741 T3350 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=de_AT, timezone=America/Grenada
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Apple Inc. 1.6.0_65 (64-bit)/cpus=2,threads=1,free=174546056,total=316669952
   [junit4]   2> NOTE: All tests run in this JVM: [TestRangeQuery, BasicZkTest, TestJmxIntegration, TestSolrDeletionPolicy2, TestQueryUtils, TestBadConfig, TestUniqueKeyFieldResource, ResourceLoaderTest, ExternalFileFieldSortTest, TermVectorComponentDistributedTest, TestLMJelinekMercerSimilarityFactory, TestSolrQueryParser, TestMergePolicyConfig, TestFieldCollectionResource, TestOmitPositions, PreAnalyzedFieldTest, TriLevelCompositeIdRoutingTest, FastVectorHighlighterTest, NotRequiredUniqueKeyTest, TestIBSimilarityFactory, SuggesterFSTTest, HdfsChaosMonkeySafeLeaderTest, UpdateRequestProcessorFactoryTest, SimpleFacetsTest, TestNumberUtils, TestRemoteStreaming, DistributedTermsComponentTest, TestLuceneMatchVersion, HdfsRecoveryZkTest, TestFuzzyAnalyzedSuggestions, TestDistribDocBasedVersion, TestManagedSchema, BasicDistributedZkTest, TestCollationField, TestCopyFieldCollectionResource, TestJmxMonitoredMap, TestDFRSimilarityFactory, ResponseLogComponentTest, SystemInfoHandlerTest, TestShardHandlerFactory, TestNoOpRegenerator, StatsComponentTest, StatelessScriptUpdateProcessorFactoryTest, TestSystemIdResolver, DistributedDebugComponentTest, DirectUpdateHandlerOptimizeTest, XsltUpdateRequestHandlerTest, TestSuggestSpellingConverter, TestExtendedDismaxParser, EnumFieldTest, HighlighterTest, DistributedSpellCheckComponentTest, StandardRequestHandlerTest, TestSort, XmlUpdateRequestHandlerTest, AlternateDirectoryTest, AssignTest, DirectSolrSpellCheckerTest, TestFiltering, SliceStateUpdateTest, BadIndexSchemaTest, SolrInfoMBeanTest, HdfsDirectoryTest, AddBlockUpdateTest, TestBM25SimilarityFactory, ClusterStateUpdateTest, TestImplicitCoreProperties, BlockCacheTest, ConvertedLegacyTest, ReturnFieldsTest, TestRecovery, TestManagedSchemaFieldResource, PingRequestHandlerTest, CollectionsAPIDistributedZkTest, InfoHandlerTest, TestSearchPerf, NumericFieldsTest, TestSolrQueryParserResource, LegacyHTMLStripCharFilterTest, TestPartialUpdateDeduplication, SolrIndexSplitterTest, FieldAnalysisRequestHandlerTest, TestSolrCoreProperties, TestRandomMergePolicy, SolrXmlInZkTest, CacheHeaderTest, SyncSliceTest, BasicDistributedZk2Test, TestAnalyzedSuggestions, TestDocumentBuilder, SoftAutoCommitTest, FileUtilsTest, RequiredFieldsTest, TestSchemaVersionResource, DateFieldTest, TestDistributedSearch, SpellPossibilityIteratorTest, SampleTest, DocValuesMissingTest, ShardSplitTest]
   [junit4] Completed in 50.61s, 1 test, 1 failure <<< FAILURES!

[...truncated 746 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:426: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:406: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:492: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1276: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:912: There were test failures: 345 suites, 1505 tests, 1 failure, 39 ignored (5 assumptions)

Total time: 84 minutes 25 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.6.0 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 1028 - Still Failing!

Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/1028/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseParallelGC

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

Error Message:
Expected content type application/octet-stream but got text/html;charset=ISO-8859-1. <html> <head> <meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/> <title>Error 404 Can not find: /onenodecollectioncore/update</title> </head> <body> <h2>HTTP ERROR: 404</h2> <p>Problem accessing /onenodecollectioncore/update. Reason: <pre>    Can not find: /onenodecollectioncore/update</pre></p> <hr /><i><small>Powered by Jetty://</small></i>                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     </body> </html> 

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Expected content type application/octet-stream but got text/html;charset=ISO-8859-1. <html>
<head>
<meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/>
<title>Error 404 Can not find: /onenodecollectioncore/update</title>
</head>
<body>
<h2>HTTP ERROR: 404</h2>
<p>Problem accessing /onenodecollectioncore/update. Reason:
<pre>    Can not find: /onenodecollectioncore/update</pre></p>
<hr /><i><small>Powered by Jetty://</small></i>
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
</body>
</html>

	at __randomizedtesting.SeedInfo.seed([9CBB76B3CD041475:1D5DF8ABBA5B7449]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:455)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:197)
	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
	at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:196)
	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:88)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
	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:606)
	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:744)


REGRESSION:  org.apache.solr.cloud.UnloadDistributedZkTest.testDistribSearch

Error Message:
Still found shard2 in collection test_unload_shard_and_collection

Stack Trace:
java.lang.AssertionError: Still found shard2 in collection test_unload_shard_and_collection
	at __randomizedtesting.SeedInfo.seed([9CBB76B3CD041475:1D5DF8ABBA5B7449]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.UnloadDistributedZkTest.testUnloadShardAndCollection(UnloadDistributedZkTest.java:128)
	at org.apache.solr.cloud.UnloadDistributedZkTest.doTest(UnloadDistributedZkTest.java:78)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
	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:606)
	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:744)


REGRESSION:  org.apache.solr.core.TestSolrXmlPersistor.simpleCoreDescriptorIsPersisted

Error Message:
expected:<...r><cores>     <core [instanceDir="instance/dir/" name="testcore]"/> </cores></solr>> but was:<...r><cores>     <core [name="testcore" instanceDir="instance/dir/]"/> </cores></solr>>

Stack Trace:
org.junit.ComparisonFailure: expected:<...r><cores>
    <core [instanceDir="instance/dir/" name="testcore]"/>
</cores></solr>> but was:<...r><cores>
    <core [name="testcore" instanceDir="instance/dir/]"/>
</cores></solr>>
	at __randomizedtesting.SeedInfo.seed([9CBB76B3CD041475:FCCBD6C165B680E7]:0)
	at org.junit.Assert.assertEquals(Assert.java:125)
	at org.junit.Assert.assertEquals(Assert.java:147)
	at org.apache.solr.core.TestSolrXmlPersistor.simpleCoreDescriptorIsPersisted(TestSolrXmlPersistor.java:81)
	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:606)
	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:744)




Build Log:
[...truncated 10021 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
   [junit4]   2> 271705 T448 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 271713 T448 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1385285278957
   [junit4]   2> 271714 T448 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 271726 T449 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 271731 T448 oasc.ZkTestServer.run start zk server on port:52430
   [junit4]   2> 271752 T448 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 271770 T455 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5251a0e1 name:ZooKeeperConnection Watcher:127.0.0.1:52430 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 271771 T448 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 271773 T448 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 271803 T448 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 271808 T457 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f1bfd88 name:ZooKeeperConnection Watcher:127.0.0.1:52430/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 271808 T448 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 271808 T448 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 271815 T448 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 271832 T448 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 271837 T448 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 271847 T448 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 271848 T448 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 271857 T448 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 271857 T448 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 271863 T448 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 271864 T448 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 271869 T448 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 271870 T448 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 271875 T448 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 271875 T448 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 271880 T448 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 271881 T448 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 271886 T448 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 271887 T448 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 271893 T448 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 271893 T448 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 271898 T448 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 271899 T448 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 271905 T448 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 271905 T448 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 271911 T448 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 271911 T448 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 272224 T448 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 272230 T448 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52433
   [junit4]   2> 272231 T448 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 272231 T448 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 272231 T448 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1385285279162
   [junit4]   2> 272232 T448 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1385285279162/'
   [junit4]   2> 272262 T448 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1385285279162/solr.xml
   [junit4]   2> 272330 T448 oasc.CoreContainer.<init> New CoreContainer 1393343343
   [junit4]   2> 272330 T448 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1385285279162/]
   [junit4]   2> 272332 T448 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 272332 T448 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 272332 T448 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 272332 T448 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 272333 T448 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 272333 T448 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 272333 T448 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 272333 T448 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 272334 T448 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 272348 T448 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 272348 T448 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 272348 T448 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 272349 T448 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52430/solr
   [junit4]   2> 272349 T448 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 272350 T448 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 272355 T468 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ef18ce1 name:ZooKeeperConnection Watcher:127.0.0.1:52430 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 272356 T448 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 272361 T448 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 272364 T470 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@25c89cca name:ZooKeeperConnection Watcher:127.0.0.1:52430/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 272364 T448 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 272370 T448 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 272379 T448 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 272387 T448 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 272393 T448 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52433_
   [junit4]   2> 272394 T448 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52433_
   [junit4]   2> 272403 T448 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 272414 T448 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 272421 T448 oasc.Overseer.start Overseer (id=90786056043364355-127.0.0.1:52433_-n_0000000000) starting
   [junit4]   2> 272430 T448 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 272441 T472 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 272442 T448 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 272448 T448 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 272453 T448 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 272462 T471 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 272469 T473 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 272470 T473 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 272472 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 272473 T473 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 272477 T471 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 272479 T471 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:52433",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52433_",
   [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> 272479 T471 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 272479 T471 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 272486 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 272488 T470 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> 273474 T473 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 273474 T473 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1385285279162/collection1
   [junit4]   2> 273475 T473 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 273476 T473 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 273476 T473 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 273479 T473 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1385285279162/collection1/'
   [junit4]   2> 273480 T473 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1385285279162/collection1/lib/classes/' to classloader
   [junit4]   2> 273481 T473 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1385285279162/collection1/lib/README' to classloader
   [junit4]   2> 273541 T473 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 273602 T473 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 273606 T473 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 273614 T473 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 274144 T473 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 274146 T473 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 274147 T473 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 274155 T473 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 274158 T473 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 274202 T473 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 274209 T473 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 274215 T473 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 274220 T473 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 274220 T473 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 274220 T473 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 274224 T473 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 274224 T473 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 274224 T473 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 274225 T473 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1385285279162/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1385285278957/control/data/
   [junit4]   2> 274225 T473 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3687196c
   [junit4]   2> 274226 T473 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1385285278957/control/data
   [junit4]   2> 274226 T473 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1385285278957/control/data/index/
   [junit4]   2> 274227 T473 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1385285278957/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 274227 T473 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1385285278957/control/data/index
   [junit4]   2> 274228 T473 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=43, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8038588667677848]
   [junit4]   2> 274229 T473 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@260c2911 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@43ccf2f9),segFN=segments_1,generation=1}
   [junit4]   2> 274229 T473 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 274234 T473 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 274235 T473 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 274235 T473 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 274236 T473 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 274236 T473 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 274236 T473 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 274237 T473 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 274237 T473 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 274237 T473 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 274237 T473 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 274238 T473 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 274238 T473 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 274238 T473 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 274239 T473 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 274239 T473 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 274240 T473 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 274250 T473 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 274254 T473 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 274255 T473 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 274255 T473 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=495717085, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 274256 T473 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@260c2911 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@43ccf2f9),segFN=segments_1,generation=1}
   [junit4]   2> 274256 T473 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 274256 T473 oass.SolrIndexSearcher.<init> Opening Searcher@2a3ddbe2 main
   [junit4]   2> 274260 T474 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2a3ddbe2 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 274261 T473 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 274261 T473 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52433 collection:control_collection shard:shard1
   [junit4]   2> 274263 T473 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 274284 T473 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 274290 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 274291 T473 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 274291 T473 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C267 name=collection1 org.apache.solr.core.SolrCore@5b19adfb url=http://127.0.0.1:52433/collection1 node=127.0.0.1:52433_ C267_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:52433, core=collection1, node_name=127.0.0.1:52433_}
   [junit4]   2> 274292 T473 C267 P52433 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52433/collection1/
   [junit4]   2> 274292 T473 C267 P52433 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 274292 T473 C267 P52433 oasc.SyncStrategy.syncToMe http://127.0.0.1:52433/collection1/ has no replicas
   [junit4]   2> 274293 T473 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52433/collection1/ shard1
   [junit4]   2> 274293 T473 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 274297 T471 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 274308 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 274312 T470 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> 274324 T471 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 274334 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 274441 T470 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> 274470 T473 oasc.ZkController.register We are http://127.0.0.1:52433/collection1/ and leader is http://127.0.0.1:52433/collection1/
   [junit4]   2> 274470 T473 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52433
   [junit4]   2> 274470 T473 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 274471 T473 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 274471 T473 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 274473 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 274473 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 274473 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 274474 T473 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 274476 T448 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 274477 T448 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 274477 T471 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 274478 T471 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52433",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52433_",
   [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":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 274480 T448 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 274484 T477 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@572fe817 name:ZooKeeperConnection Watcher:127.0.0.1:52430/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 274484 T448 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 274488 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 274489 T448 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 274496 T448 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 274594 T470 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> 274602 T477 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> 274832 T448 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 274836 T448 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52437
   [junit4]   2> 274838 T448 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 274839 T448 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 274839 T448 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1385285281740
   [junit4]   2> 274839 T448 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1385285281740/'
   [junit4]   2> 274871 T448 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1385285281740/solr.xml
   [junit4]   2> 274938 T448 oasc.CoreContainer.<init> New CoreContainer 2143031616
   [junit4]   2> 274939 T448 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1385285281740/]
   [junit4]   2> 274940 T448 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 274940 T448 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 274941 T448 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 274941 T448 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 274941 T448 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 274942 T448 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 274942 T448 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 274942 T448 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 274942 T448 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 274959 T448 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 274960 T448 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 274960 T448 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 274960 T448 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52430/solr
   [junit4]   2> 274961 T448 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 274962 T448 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 274966 T488 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5f2308c9 name:ZooKeeperConnection Watcher:127.0.0.1:52430 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 274967 T448 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 274972 T448 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 274975 T490 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@125d42b6 name:ZooKeeperConnection Watcher:127.0.0.1:52430/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 274975 T448 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 274987 T448 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 275996 T448 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52437_
   [junit4]   2> 275999 T448 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52437_
   [junit4]   2> 276008 T477 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 276008 T470 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 276009 T490 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 276028 T491 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 276028 T491 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 276031 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 276031 T491 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 276031 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 276032 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 276036 T471 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 276038 T471 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:52437",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52437_",
   [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> 276038 T471 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 276038 T471 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 276046 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 276153 T477 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> 276153 T490 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> 276153 T470 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> 277033 T491 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 277033 T491 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1385285281740/collection1
   [junit4]   2> 277033 T491 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 277035 T491 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 277035 T491 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 277038 T491 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1385285281740/collection1/'
   [junit4]   2> 277040 T491 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1385285281740/collection1/lib/classes/' to classloader
   [junit4]   2> 277041 T491 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1385285281740/collection1/lib/README' to classloader
   [junit4]   2> 277113 T491 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 277162 T491 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 277167 T491 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 277174 T491 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 277692 T491 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 277694 T491 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 277694 T491 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 277703 T491 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 277706 T491 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 277738 T491 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 277745 T491 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 277751 T491 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 277755 T491 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 277755 T491 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 277756 T491 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 277759 T491 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 277759 T491 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 277760 T491 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 277760 T491 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1385285281740/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1385285278957/jetty1/
   [junit4]   2> 277760 T491 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3687196c
   [junit4]   2> 277761 T491 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1385285278957/jetty1
   [junit4]   2> 277762 T491 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1385285278957/jetty1/index/
   [junit4]   2> 277762 T491 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1385285278957/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 277762 T491 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1385285278957/jetty1/index
   [junit4]   2> 277763 T491 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=43, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8038588667677848]
   [junit4]   2> 277764 T491 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@650e3c66 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@72eb6a93),segFN=segments_1,generation=1}
   [junit4]   2> 277764 T491 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 277772 T491 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 277772 T491 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 277773 T491 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 277773 T491 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 277773 T491 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 277773 T491 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 277774 T491 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 277774 T491 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 277774 T491 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 277775 T491 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 277775 T491 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 277775 T491 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 277776 T491 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 277776 T491 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 277777 T491 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 277777 T491 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 277788 T491 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 277793 T491 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 277793 T491 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 277795 T491 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=495717085, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 277795 T491 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@650e3c66 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@72eb6a93),segFN=segments_1,generation=1}
   [junit4]   2> 277795 T491 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 277796 T491 oass.SolrIndexSearcher.<init> Opening Searcher@25a92c92 main
   [junit4]   2> 277801 T492 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@25a92c92 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 277803 T491 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 277804 T491 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52437 collection:collection1 shard:shard2
   [junit4]   2> 277805 T491 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 277824 T491 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 277829 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 277829 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 277829 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 277829 T491 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 277830 T491 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C268 name=collection1 org.apache.solr.core.SolrCore@6a5c03c7 url=http://127.0.0.1:52437/collection1 node=127.0.0.1:52437_ C268_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:52437, core=collection1, node_name=127.0.0.1:52437_}
   [junit4]   2> 277830 T491 C268 P52437 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52437/collection1/
   [junit4]   2> 277830 T491 C268 P52437 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 277830 T491 C268 P52437 oasc.SyncStrategy.syncToMe http://127.0.0.1:52437/collection1/ has no replicas
   [junit4]   2> 277830 T491 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52437/collection1/ shard2
   [junit4]   2> 277831 T491 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 277832 T471 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 277840 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 277842 T490 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> 277843 T470 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> 277843 T477 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> 277859 T471 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 277866 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 277973 T477 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> 277973 T490 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> 277973 T470 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> 278015 T491 oasc.ZkController.register We are http://127.0.0.1:52437/collection1/ and leader is http://127.0.0.1:52437/collection1/
   [junit4]   2> 278015 T491 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52437
   [junit4]   2> 278016 T491 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 278016 T491 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 278016 T491 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 278018 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 278019 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 278019 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 278019 T491 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 278022 T448 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 278023 T448 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 278024 T471 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 278025 T471 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:52437",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52437_",
   [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_node1"}
   [junit4]   2> 278032 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 278137 T470 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> 278138 T477 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> 278145 T490 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> 278335 T448 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 278339 T448 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52440
   [junit4]   2> 278340 T448 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 278341 T448 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 278341 T448 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1385285285269
   [junit4]   2> 278341 T448 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1385285285269/'
   [junit4]   2> 278373 T448 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1385285285269/solr.xml
   [junit4]   2> 278465 T448 oasc.CoreContainer.<init> New CoreContainer 1192022496
   [junit4]   2> 278466 T448 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1385285285269/]
   [junit4]   2> 278467 T448 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 278467 T448 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 278467 T448 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 278468 T448 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 278468 T448 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 278468 T448 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 278468 T448 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 278469 T448 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 278469 T448 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 278484 T448 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 278485 T448 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 278485 T448 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 278485 T448 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52430/solr
   [junit4]   2> 278486 T448 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 278487 T448 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 278492 T504 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10441c04 name:ZooKeeperConnection Watcher:127.0.0.1:52430 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 278492 T448 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 278499 T448 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 278503 T506 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@52b0a70f name:ZooKeeperConnection Watcher:127.0.0.1:52430/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 278503 T448 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 278515 T448 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 279524 T448 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52440_
   [junit4]   2> 279528 T448 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52440_
   [junit4]   2> 279536 T470 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 279537 T506 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 279537 T490 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 279537 T477 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 279553 T507 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 279553 T507 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 279555 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 279555 T507 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 279555 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 279556 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 279559 T471 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 279561 T471 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:52440",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52440_",
   [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> 279561 T471 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 279562 T471 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 279569 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 279680 T470 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> 279680 T506 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> 279680 T477 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> 279680 T490 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> 280557 T507 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 280558 T507 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1385285285269/collection1
   [junit4]   2> 280558 T507 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 280560 T507 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 280560 T507 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 280562 T507 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1385285285269/collection1/'
   [junit4]   2> 280563 T507 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1385285285269/collection1/lib/classes/' to classloader
   [junit4]   2> 280564 T507 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1385285285269/collection1/lib/README' to classloader
   [junit4]   2> 280630 T507 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 280691 T507 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 280694 T507 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 280703 T507 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 281234 T507 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 281235 T507 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 281236 T507 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 281245 T507 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 281248 T507 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 281281 T507 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 281287 T507 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 281292 T507 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 281296 T507 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 281296 T507 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 281296 T507 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 281299 T507 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 281299 T507 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 281300 T507 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 281300 T507 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1385285285269/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1385285278957/jetty2/
   [junit4]   2> 281300 T507 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3687196c
   [junit4]   2> 281301 T507 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1385285278957/jetty2
   [junit4]   2> 281301 T507 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1385285278957/jetty2/index/
   [junit4]   2> 281301 T507 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1385285278957/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 281302 T507 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1385285278957/jetty2/index
   [junit4]   2> 281302 T507 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=43, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8038588667677848]
   [junit4]   2> 281303 T507 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1fb6efb9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@205735fa),segFN=segments_1,generation=1}
   [junit4]   2> 281303 T507 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 281307 T507 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 281308 T507 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 281308 T507 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 281308 T507 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 281308 T507 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 281308 T507 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 281309 T507 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 281310 T507 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 281310 T507 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 281311 T507 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 281311 T507 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 281312 T507 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 281312 T507 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 281312 T507 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 281313 T507 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 281313 T507 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 281322 T507 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 281327 T507 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 281328 T507 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 281328 T507 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=495717085, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 281329 T507 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1fb6efb9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@205735fa),segFN=segments_1,generation=1}
   [junit4]   2> 281329 T507 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 281329 T507 oass.SolrIndexSearcher.<init> Opening Searcher@9d9db77 main
   [junit4]   2> 281338 T508 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9d9db77 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 281342 T507 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 281342 T507 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52440 collection:collection1 shard:shard1
   [junit4]   2> 281347 T507 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 281368 T507 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 281373 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 281374 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 281374 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 281375 T507 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 281375 T507 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C269 name=collection1 org.apache.solr.core.SolrCore@72dd0828 url=http://127.0.0.1:52440/collection1 node=127.0.0.1:52440_ C269_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:52440, core=collection1, node_name=127.0.0.1:52440_}
   [junit4]   2> 281376 T507 C269 P52440 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52440/collection1/
   [junit4]   2> 281376 T507 C269 P52440 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 281377 T507 C269 P52440 oasc.SyncStrategy.syncToMe http://127.0.0.1:52440/collection1/ has no replicas
   [junit4]   2> 281377 T507 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52440/collection1/ shard1
   [junit4]   2> 281378 T507 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 281378 T471 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 281388 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 281391 T490 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> 281391 T506 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> 281392 T477 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> 281392 T470 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> 281407 T471 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 281416 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 281524 T506 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> 281524 T470 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> 281525 T477 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> 281525 T490 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> 281560 T507 oasc.ZkController.register We are http://127.0.0.1:52440/collection1/ and leader is http://127.0.0.1:52440/collection1/
   [junit4]   2> 281560 T507 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52440
   [junit4]   2> 281561 T507 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 281561 T507 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 281561 T507 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 281563 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 281564 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 281564 T470 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 281565 T507 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 281567 T471 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 281568 T448 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-co

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

/build/solr-core/test/J0/./ZkControllerTest/solr.xml
   [junit4]   2> 2979826 T9568 oasc.CoreContainer.<init> New CoreContainer 716420343
   [junit4]   2> 2979831 T9568 oas.SolrTestCaseJ4.tearDown ###Ending simpleCoreDescriptorIsPersisted
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestSolrXmlPersistor -Dtests.method=simpleCoreDescriptorIsPersisted -Dtests.seed=9CBB76B3CD041475 -Dtests.slow=true -Dtests.locale=sl_SI -Dtests.timezone=Asia/Damascus -Dtests.file.encoding=US-ASCII
   [junit4] FAILURE 0.13s | TestSolrXmlPersistor.simpleCoreDescriptorIsPersisted <<<
   [junit4]    > Throwable #1: org.junit.ComparisonFailure: expected:<...r><cores>
   [junit4]    >     <core [instanceDir="instance/dir/" name="testcore]"/>
   [junit4]    > </cores></solr>> but was:<...r><cores>
   [junit4]    >     <core [name="testcore" instanceDir="instance/dir/]"/>
   [junit4]    > </cores></solr>>
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([9CBB76B3CD041475:FCCBD6C165B680E7]:0)
   [junit4]    > 	at org.apache.solr.core.TestSolrXmlPersistor.simpleCoreDescriptorIsPersisted(TestSolrXmlPersistor.java:81)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 2979846 T9568 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=sl_SI, timezone=Asia/Damascus
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_45 (64-bit)/cpus=2,threads=1,free=142670296,total=479723520
   [junit4]   2> NOTE: All tests run in this JVM: [UpdateRequestProcessorFactoryTest, StatelessScriptUpdateProcessorFactoryTest, TestSort, StressHdfsTest, SpellCheckCollatorTest, TestHighFrequencyDictionaryFactory, TestPHPSerializedResponseWriter, TestRandomDVFaceting, HdfsLockFactoryTest, BasicDistributedZkTest, TestSolrQueryParserResource, SuggesterWFSTTest, BadComponentTest, DirectUpdateHandlerTest, TestJmxIntegration, UUIDFieldTest, IndexBasedSpellCheckerTest, HardAutoCommitTest, DateMathParserTest, TestSerializedLuceneMatchVersion, TestCollapseQParserPlugin, BasicDistributedZk2Test, NotRequiredUniqueKeyTest, StandardRequestHandlerTest, MoreLikeThisHandlerTest, TestFastOutputStream, ShardRoutingCustomTest, SliceStateTest, ClusterStateTest, TestNumberUtils, HdfsBasicDistributedZk2Test, SolrCoreCheckLockOnStartupTest, ZkSolrClientTest, UpdateParamsTest, TestSolrXml, TestFiltering, SpatialFilterTest, EnumFieldTest, ConvertedLegacyTest, DirectSolrConnectionTest, SliceStateUpdateTest, TestReplicationHandler, TestCollationField, FieldAnalysisRequestHandlerTest, LegacyHTMLStripCharFilterTest, TestSchemaResource, TestSystemIdResolver, TestClassNameShortening, TestRangeQuery, TestFastWriter, TestSolr4Spatial, AutoCommitTest, TestCloudManagedSchema, LeaderElectionTest, URLClassifyProcessorTest, TestManagedSchema, TestStressLucene, TestRemoteStreaming, IndexSchemaTest, TestSurroundQueryParser, TestMergePolicyConfig, DirectSolrSpellCheckerTest, TestFieldResource, HdfsChaosMonkeySafeLeaderTest, TestDynamicFieldResource, TestBadConfig, DistanceFunctionTest, NumericFieldsTest, PingRequestHandlerTest, TestComponentsName, DistributedSuggesterComponentTest, OverseerCollectionProcessorTest, DistributedTermsComponentTest, TestStressReorder, ModifyConfFileTest, TestLMJelinekMercerSimilarityFactory, TestDocSet, TestLFUCache, TestAtomicUpdateErrorCases, ShardRoutingTest, RequestHandlersTest, AlternateDirectoryTest, QueryEqualityTest, ParsingFieldUpdateProcessorsTest, DocumentAnalysisRequestHandlerTest, AddSchemaFieldsUpdateProcessorFactoryTest, LeaderElectionIntegrationTest, InfoHandlerTest, TestSolrCoreProperties, TestCoreDiscovery, XmlUpdateRequestHandlerTest, TestReversedWildcardFilterFactory, TestIndexSearcher, TestPartialUpdateDeduplication, PluginInfoTest, CachingDirectoryFactoryTest, MinimalSchemaTest, TestCodecSupport, TestZkChroot, TestLazyCores, TestSchemaSimilarityResource, TestRTGBase, HdfsRecoveryZkTest, TestLMDirichletSimilarityFactory, JsonLoaderTest, TestFieldTypeResource, TestSweetSpotSimilarityFactory, CollectionsAPIDistributedZkTest, SearchHandlerTest, TestShardHandlerFactory, HdfsUnloadDistributedZkTest, TestReloadAndDeleteDocs, ExternalFileFieldSortTest, HdfsDirectoryTest, TestNoOpRegenerator, LoggingHandlerTest, TestDistributedGrouping, TestCloudManagedSchemaAddField, ZkControllerTest, FastVectorHighlighterTest, TestPhraseSuggestions, BlockDirectoryTest, DefaultValueUpdateProcessorTest, MBeansHandlerTest, TermVectorComponentDistributedTest, CoreContainerCoreInitFailuresTest, TestConfig, TestQueryTypes, PathHierarchyTokenizerFactoryTest, TestDefaultSearchFieldResource, TimeZoneUtilsTest, TestBM25SimilarityFactory, SolrCmdDistributorTest, ScriptEngineTest, TestRecovery, TestRealTimeGet, DistributedDebugComponentTest, TermsComponentTest, SolrTestCaseJ4Test, TestJmxMonitoredMap, TestFaceting, QueryResultKeyTest, TestTrie, TestMaxScoreQueryParser, OpenCloseCoreStressTest, TestAnalyzedSuggestions, CustomCollectionTest, DateFieldTest, TestWordDelimiterFilterFactory, TestFieldCollectionResource, ResponseLogComponentTest, RecoveryZkTest, TestSolrDeletionPolicy2, TestManagedSchemaFieldResource, SolrRequestParserTest, TestSearchPerf, QueryParsingTest, OpenExchangeRatesOrgProviderTest, DocValuesMultiTest, IndexSchemaRuntimeFieldTest, SolrXmlInZkTest, SolrInfoMBeanTest, TestJoin, RegexBoostProcessorTest, AddBlockUpdateTest, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, SyncSliceTest, OverseerTest, BasicZkTest, FullSolrCloudDistribCmdsTest, ClusterStateUpdateTest, TestRandomFaceting, ZkCLITest, TestDistributedSearch, TestHashPartitioner, DistributedSpellCheckComponentTest, TestMultiCoreConfBootstrap, TestReload, TestStressVersions, TestCoreContainer, SimpleFacetsTest, SolrCoreTest, StatsComponentTest, SpellCheckComponentTest, TestGroupingSearch, QueryElevationComponentTest, PeerSyncTest, BadIndexSchemaTest, TestFunctionQuery, BasicFunctionalityTest, HighlighterTest, SoftAutoCommitTest, ShowFileRequestHandlerTest, CurrencyFieldOpenExchangeTest, DistributedQueryElevationComponentTest, CurrencyFieldXmlFileTest, SolrIndexSplitterTest, SimplePostToolTest, AnalysisAfterCoreReloadTest, SignatureUpdateProcessorFactoryTest, TestExtendedDismaxParser, SuggesterFSTTest, CoreAdminHandlerTest, TestFoldingMultitermQuery, DocValuesTest, SuggesterTSTTest, SuggesterTest, TestCSVLoader, PolyFieldTest, NoCacheHeaderTest, WordBreakSolrSpellCheckerTest, SchemaVersionSpecificBehaviorTest, TestPseudoReturnFields, TestUpdate, FieldMutatingUpdateProcessorTest, DirectUpdateHandlerOptimizeTest, SortByFunctionTest, TestSolrDeletionPolicy1, XsltUpdateRequestHandlerTest, DebugComponentTest, CacheHeaderTest, LukeRequestHandlerTest, DisMaxRequestHandlerTest, TestQueryUtils, TestWriterPerf, PrimitiveFieldTypeTest, TestOmitPositions, FileBasedSpellCheckerTest, DocumentBuilderTest, TestValueSourceCache, TermVectorComponentTest, TestIndexingPerformance, RequiredFieldsTest, TestSolrQueryParser, TestArbitraryIndexDir, SolrPluginUtilsTest, ReturnFieldsTest, JSONWriterTest, TestCSVResponseWriter, UniqFieldsUpdateProcessorFactoryTest, BinaryUpdateRequestHandlerTest, CSVRequestHandlerTest, TestBinaryResponseWriter, HighlighterConfigTest, SOLR749Test, TestQuerySenderListener, TestSolrIndexConfig, TestQuerySenderNoQuery, CopyFieldTest, SolrIndexConfigTest, TestStressRecovery, MultiTermTest, SampleTest, TestBinaryField, TestElisionMultitermQuery, OutputWriterTest, TestFuzzyAnalyzedSuggestions, TestPostingsSolrHighlighter, TestLuceneMatchVersion, SpellPossibilityIteratorTest, TestCharFilters, SynonymTokenizerTest, TestXIncludeConfig, EchoParamsTest, TestDFRSimilarityFactory, TestPerFieldSimilarity, TestIBSimilarityFactory, TestDefaultSimilarityFactory, ResourceLoaderTest, TestFastLRUCache, ChaosMonkeyNothingIsSafeTest, TestSolrXMLSerializer, PreAnalyzedFieldTest, PrimUtilsTest, TestSuggestSpellingConverter, SpellingQueryConverterTest, DOMUtilTest, RAMDirectoryFactoryTest, TestSolrJ, TestLRUCache, TestUtils, TestDocumentBuilder, ZkNodePropsTest, SystemInfoHandlerTest, FileUtilsTest, CircularListTest, TestCollationKeyRangeQueries, AliasIntegrationTest, AssignTest, DeleteInactiveReplicaTest, DeleteReplicaTest, DeleteShardTest, MigrateRouteKeyTest, ShardSplitTest, TestDistribDocBasedVersion, TestModifyConfFiles, TriLevelCompositeIdRoutingTest, HdfsBasicDistributedZkTest, HdfsCollectionsAPIDistributedZkTest, HdfsSyncSliceTest, TestImplicitCoreProperties, TestInfoStreamLogging, TestNRTOpen, TestNonNRTOpen, TestSolrXmlPersistence, TestSolrXmlPersistor]
   [junit4] Completed in 0.19s, 7 tests, 1 failure <<< FAILURES!

[...truncated 86 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:426: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:406: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:492: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1279: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:912: There were test failures: 345 suites, 1505 tests, 1 error, 2 failures, 40 ignored (6 assumptions)

Total time: 82 minutes 4 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure