lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 814 - Failure!
Date Wed, 18 Sep 2013 14:10:39 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/814/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC

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

Error Message:
Wrong doc count on shard1_1 expected:<81> but was:<70>

Stack Trace:
java.lang.AssertionError: Wrong doc count on shard1_1 expected:<81> but was:<70>
	at __randomizedtesting.SeedInfo.seed([CE2A9D393E9CE374:4FCC132149C38348]: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:227)
	at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:173)
	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:724)




Build Log:
[...truncated 9745 lines...]
   [junit4] Suite: org.apache.solr.cloud.ShardSplitTest
   [junit4]   2> log4j:WARN No such property [conversionPattern] in org.apache.solr.util.SolrLogLayout.
   [junit4]   2> 3985 T11 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 4122 T11 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-1379509736573
   [junit4]   2> 4145 T11 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 4156 T12 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 4464 T11 oasc.ZkTestServer.run start zk server on port:52100
   [junit4]   2> 4897 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 5317 T13 oazs.NIOServerCnxn.doIO WARN Exception causing close of session 0x0 due to java.io.IOException: ZooKeeperServer not running
   [junit4]   2> 6580 T18 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2d2e86c name:ZooKeeperConnection Watcher:127.0.0.1:52100 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 6581 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 6591 T11 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 6780 T20 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2987460a name:ZooKeeperConnection Watcher:127.0.0.1:52100/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 6782 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 6783 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 6823 T11 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 6845 T11 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 6862 T11 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 6879 T11 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 6895 T11 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> 6952 T11 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 6990 T11 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> 6992 T11 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 7013 T11 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> 7015 T11 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 7045 T11 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> 7047 T11 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 7069 T11 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> 7071 T11 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 7135 T11 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> 7137 T11 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 7151 T11 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> 7154 T11 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 7168 T11 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> 7170 T11 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 7190 T11 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> 7193 T11 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 7209 T11 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> 7211 T11 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 8911 T11 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 9386 T11 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52104
   [junit4]   2> 9489 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 9524 T11 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 9526 T11 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-controljetty-1379509739686
   [junit4]   2> 9530 T11 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-controljetty-1379509739686/'
   [junit4]   2> 10388 T11 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-controljetty-1379509739686/solr.xml
   [junit4]   2> 11102 T11 oasc.CoreContainer.<init> New CoreContainer 872723111
   [junit4]   2> 11104 T11 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-controljetty-1379509739686/]
   [junit4]   2> 11292 T11 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 11293 T11 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 11294 T11 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 11295 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 11296 T11 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 11297 T11 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 11298 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 11299 T11 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 11300 T11 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 11375 T11 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 12430 T11 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 12440 T11 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 12457 T11 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52100/solr
   [junit4]   2> 12495 T11 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 12506 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 12525 T32 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@267cae35 name:ZooKeeperConnection Watcher:127.0.0.1:52100 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 12528 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 12548 T11 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 12617 T34 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4bb820a5 name:ZooKeeperConnection Watcher:127.0.0.1:52100/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 12619 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 12621 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 12651 T11 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 12686 T11 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 12736 T11 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 12747 T11 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52104_
   [junit4]   2> 12765 T11 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52104_
   [junit4]   2> 12794 T11 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 12874 T11 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 12888 T11 oasc.Overseer.start Overseer (id=90407550129537027-127.0.0.1:52104_-n_0000000000) starting
   [junit4]   2> 12940 T11 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 12987 T36 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 12993 T11 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 13008 T11 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 13028 T11 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 13068 T35 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 13836 T37 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 13838 T37 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 13844 T37 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 14629 T35 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 14643 T35 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52104_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52104"}
   [junit4]   2> 14645 T35 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 14689 T35 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 14736 T34 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> 14846 T37 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 14848 T37 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-controljetty-1379509739686/collection1
   [junit4]   2> 14850 T37 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 14854 T37 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 14855 T37 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 14881 T37 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-controljetty-1379509739686/collection1/'
   [junit4]   2> 14889 T37 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-1379509739686/collection1/lib/classes/' to classloader
   [junit4]   2> 14891 T37 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-1379509739686/collection1/lib/README' to classloader
   [junit4]   2> 15351 T37 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 15762 T37 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 15802 T37 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 16036 T37 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 18890 T37 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 18897 T37 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 18911 T37 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 18937 T37 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 20338 T37 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 20409 T37 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-controljetty-1379509739686/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1379509736572/control/data/
   [junit4]   2> 20423 T37 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@74d0d91c
   [junit4]   2> 20926 T37 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1379509736572/control/data
   [junit4]   2> 20927 T37 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1379509736572/control/data/index/
   [junit4]   2> 20928 T37 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1379509736572/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 20944 T37 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1379509736572/control/data/index
   [junit4]   2> 20949 T37 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=39, maxMergeAtOnceExplicit=49, maxMergedSegmentMB=95.8388671875, floorSegmentMB=0.4375, forceMergeDeletesPctAllowed=1.9355945343415182, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 21201 T37 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@76abf71 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@417de6ff),segFN=segments_1,generation=1}
   [junit4]   2> 21207 T37 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 22469 T37 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 22616 T37 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 22646 T37 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 22647 T37 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 22649 T37 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 22649 T37 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 22812 T37 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 22813 T37 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 22814 T37 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 22882 T37 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 22915 T37 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 22916 T37 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 22922 T37 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 22968 T37 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 22975 T37 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 23150 T37 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 23319 T37 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 23320 T37 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 23326 T37 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=616193555, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 23330 T37 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@76abf71 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@417de6ff),segFN=segments_1,generation=1}
   [junit4]   2> 23330 T37 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 23417 T37 oass.SolrIndexSearcher.<init> Opening Searcher@79ee400 main
   [junit4]   2> 23734 T38 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@79ee400 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 23748 T37 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 23749 T37 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52104 collection:control_collection shard:shard1
   [junit4]   2> 23767 T37 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 23815 T37 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 23855 T37 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 23866 T37 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 23867 T37 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 23869 T37 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52104/collection1/
   [junit4]   2> 23870 T37 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 23871 T37 oasc.SyncStrategy.syncToMe http://127.0.0.1:52104/collection1/ has no replicas
   [junit4]   2> 23872 T37 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52104/collection1/ shard1
   [junit4]   2> 23873 T37 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 25310 T35 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 25341 T34 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> 25398 T37 oasc.ZkController.register We are http://127.0.0.1:52104/collection1/ and leader is http://127.0.0.1:52104/collection1/
   [junit4]   2> 25405 T37 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52104
   [junit4]   2> 25406 T37 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 25407 T37 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 25408 T37 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 25415 T37 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 25429 T11 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 25430 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 25498 T11 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 25551 T11 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 25559 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 25564 T41 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7883822a name:ZooKeeperConnection Watcher:127.0.0.1:52100/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 25565 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 25571 T11 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 25585 T11 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 26067 T11 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 26074 T11 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52108
   [junit4]   2> 26077 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 26078 T11 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 26079 T11 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-1379509758034
   [junit4]   2> 26080 T11 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-1379509758034/'
   [junit4]   2> 26130 T11 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-1379509758034/solr.xml
   [junit4]   2> 26400 T11 oasc.CoreContainer.<init> New CoreContainer 653554517
   [junit4]   2> 26406 T11 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-1379509758034/]
   [junit4]   2> 26413 T11 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 26417 T11 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 26419 T11 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 26420 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 26421 T11 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 26426 T11 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 26427 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 26429 T11 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 26430 T11 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 26434 T11 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 26486 T11 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 26488 T11 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 26491 T11 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52100/solr
   [junit4]   2> 26492 T11 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 26501 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 26525 T52 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@31e51ba4 name:ZooKeeperConnection Watcher:127.0.0.1:52100 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 26526 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 26552 T11 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 26576 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 26582 T54 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@45d14aaa name:ZooKeeperConnection Watcher:127.0.0.1:52100/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 26583 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 26598 T11 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 26872 T35 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 26876 T35 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52104_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52104"}
   [junit4]   2> 26895 T41 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> 26896 T54 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> 26896 T34 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> 27611 T11 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52108_
   [junit4]   2> 27616 T11 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52108_
   [junit4]   2> 27628 T54 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 27629 T54 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 27630 T34 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 27631 T34 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 27633 T41 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 27634 T41 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 27680 T55 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 27682 T55 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 27688 T55 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 28417 T35 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 28421 T35 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52108_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52108"}
   [junit4]   2> 28421 T35 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 28422 T35 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 28440 T54 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> 28441 T41 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> 28443 T34 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> 28691 T55 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 28692 T55 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-1379509758034/collection1
   [junit4]   2> 28693 T55 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 28696 T55 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 28696 T55 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 28700 T55 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-1379509758034/collection1/'
   [junit4]   2> 28702 T55 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-1379509758034/collection1/lib/classes/' to classloader
   [junit4]   2> 28703 T55 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-1379509758034/collection1/lib/README' to classloader
   [junit4]   2> 28879 T55 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 29048 T55 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 29054 T55 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 29211 T55 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 30175 T55 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 30184 T55 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 30189 T55 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 30202 T55 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 30366 T55 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 30368 T55 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-1379509758034/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty1/
   [junit4]   2> 30369 T55 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@74d0d91c
   [junit4]   2> 30379 T55 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty1
   [junit4]   2> 30381 T55 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty1/index/
   [junit4]   2> 30382 T55 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 30384 T55 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty1/index
   [junit4]   2> 30386 T55 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=39, maxMergeAtOnceExplicit=49, maxMergedSegmentMB=95.8388671875, floorSegmentMB=0.4375, forceMergeDeletesPctAllowed=1.9355945343415182, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 30390 T55 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@78ed841c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@617b75b0),segFN=segments_1,generation=1}
   [junit4]   2> 30391 T55 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 30412 T55 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 30415 T55 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 30417 T55 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 30418 T55 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 30420 T55 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 30421 T55 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 30424 T55 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 30426 T55 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 30427 T55 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 30434 T55 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 30441 T55 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 30442 T55 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 30444 T55 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 30450 T55 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 30452 T55 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 30476 T55 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 30491 T55 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 30492 T55 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 30499 T55 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=616193555, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 30502 T55 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@78ed841c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@617b75b0),segFN=segments_1,generation=1}
   [junit4]   2> 30502 T55 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 30503 T55 oass.SolrIndexSearcher.<init> Opening Searcher@27c98168 main
   [junit4]   2> 30553 T56 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@27c98168 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 30571 T55 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 30572 T55 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52108 collection:collection1 shard:shard1
   [junit4]   2> 30574 T55 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 30612 T55 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 30649 T55 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 30660 T55 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 30661 T55 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 30661 T55 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52108/collection1/
   [junit4]   2> 30662 T55 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 30663 T55 oasc.SyncStrategy.syncToMe http://127.0.0.1:52108/collection1/ has no replicas
   [junit4]   2> 30663 T55 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52108/collection1/ shard1
   [junit4]   2> 30664 T55 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 31513 T35 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 31548 T34 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> 31549 T41 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> 31549 T54 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> 31562 T55 oasc.ZkController.register We are http://127.0.0.1:52108/collection1/ and leader is http://127.0.0.1:52108/collection1/
   [junit4]   2> 31563 T55 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52108
   [junit4]   2> 31563 T55 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 31564 T55 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 31565 T55 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 31576 T55 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 31584 T11 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 31585 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 31587 T11 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 32200 T11 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 32211 T11 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52111
   [junit4]   2> 32228 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 32229 T11 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 32230 T11 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-1379509764061
   [junit4]   2> 32231 T11 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-1379509764061/'
   [junit4]   2> 32295 T11 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-1379509764061/solr.xml
   [junit4]   2> 32469 T11 oasc.CoreContainer.<init> New CoreContainer 472291917
   [junit4]   2> 32471 T11 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-1379509764061/]
   [junit4]   2> 32475 T11 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 32476 T11 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 32477 T11 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 32478 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 32479 T11 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 32479 T11 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 32480 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 32481 T11 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 32482 T11 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 32483 T11 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 32509 T11 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 32510 T11 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 32511 T11 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52100/solr
   [junit4]   2> 32512 T11 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 32516 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 32522 T68 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6fa3d735 name:ZooKeeperConnection Watcher:127.0.0.1:52100 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 32524 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 32537 T11 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 32584 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 32590 T70 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3f424adc name:ZooKeeperConnection Watcher:127.0.0.1:52100/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 32591 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 32612 T11 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 33083 T35 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 33088 T35 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52108_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52108"}
   [junit4]   2> 33107 T34 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> 33109 T41 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> 33108 T70 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> 33109 T54 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> 33638 T11 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52111_
   [junit4]   2> 33641 T11 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52111_
   [junit4]   2> 33652 T70 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 33655 T54 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 33656 T54 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 33656 T34 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 33657 T34 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 33656 T41 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 33662 T41 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 33674 T70 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 33693 T71 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 33694 T71 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 33698 T71 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 34636 T35 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 34640 T35 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52111_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52111"}
   [junit4]   2> 34641 T35 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 34642 T35 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 34660 T70 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> 34661 T34 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> 34663 T54 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> 34663 T41 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> 34702 T71 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 34703 T71 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-1379509764061/collection1
   [junit4]   2> 34704 T71 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 34707 T71 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 34708 T71 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 34714 T71 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-1379509764061/collection1/'
   [junit4]   2> 34717 T71 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-1379509764061/collection1/lib/classes/' to classloader
   [junit4]   2> 34719 T71 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-1379509764061/collection1/lib/README' to classloader
   [junit4]   2> 34891 T71 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 34995 T71 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 35001 T71 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 35130 T71 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 36246 T71 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 36253 T71 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 36258 T71 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 36271 T71 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 36406 T71 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 36407 T71 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-1379509764061/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty2/
   [junit4]   2> 36407 T71 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@74d0d91c
   [junit4]   2> 36413 T71 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty2
   [junit4]   2> 36413 T71 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty2/index/
   [junit4]   2> 36414 T71 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 36416 T71 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty2/index
   [junit4]   2> 36417 T71 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=39, maxMergeAtOnceExplicit=49, maxMergedSegmentMB=95.8388671875, floorSegmentMB=0.4375, forceMergeDeletesPctAllowed=1.9355945343415182, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 36422 T71 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@728b49e2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@14d04dcd),segFN=segments_1,generation=1}
   [junit4]   2> 36423 T71 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 36435 T71 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 36436 T71 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 36437 T71 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 36438 T71 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 36438 T71 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 36439 T71 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 36441 T71 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 36442 T71 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 36442 T71 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 36445 T71 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 36450 T71 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 36451 T71 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 36453 T71 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 36459 T71 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 36462 T71 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 36484 T71 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 36492 T71 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 36493 T71 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 36496 T71 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=616193555, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 36497 T71 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@728b49e2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@14d04dcd),segFN=segments_1,generation=1}
   [junit4]   2> 36498 T71 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 36499 T71 oass.SolrIndexSearcher.<init> Opening Searcher@4ba32423 main
   [junit4]   2> 36529 T72 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4ba32423 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 36534 T71 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 36535 T71 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52111 collection:collection1 shard:shard2
   [junit4]   2> 36535 T71 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 36557 T71 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 36578 T71 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 36586 T71 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 36587 T71 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 36588 T71 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52111/collection1/
   [junit4]   2> 36589 T71 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 36589 T71 oasc.SyncStrategy.syncToMe http://127.0.0.1:52111/collection1/ has no replicas
   [junit4]   2> 36590 T71 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52111/collection1/ shard2
   [junit4]   2> 36590 T71 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 37709 T35 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 37742 T34 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> 37743 T41 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> 37742 T54 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> 37743 T70 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> 37792 T71 oasc.ZkController.register We are http://127.0.0.1:52111/collection1/ and leader is http://127.0.0.1:52111/collection1/
   [junit4]   2> 37793 T71 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52111
   [junit4]   2> 37793 T71 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 37794 T71 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 37795 T71 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 37801 T71 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 37806 T11 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 37807 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 37808 T11 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 38296 T11 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 38301 T11 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52114
   [junit4]   2> 38303 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 38304 T11 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 38305 T11 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-jetty3-1379509770275
   [junit4]   2> 38305 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty3-1379509770275/'
   [junit4]   2> 38356 T11 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-1379509770275/solr.xml
   [junit4]   2> 38510 T11 oasc.CoreContainer.<init> New CoreContainer 1246052888
   [junit4]   2> 38513 T11 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-jetty3-1379509770275/]
   [junit4]   2> 38517 T11 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 38518 T11 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 38519 T11 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 38523 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 38524 T11 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 38525 T11 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 38526 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 38527 T11 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 38529 T11 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 38531 T11 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 38563 T11 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 38564 T11 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 38565 T11 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52100/solr
   [junit4]   2> 38566 T11 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 38568 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 38573 T84 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7463ab39 name:ZooKeeperConnection Watcher:127.0.0.1:52100 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 38575 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 38581 T11 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 38604 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 38612 T86 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@278904b4 name:ZooKeeperConnection Watcher:127.0.0.1:52100/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 38613 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 38628 T11 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 39274 T35 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 39277 T35 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52111_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52111"}
   [junit4]   2> 39296 T70 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> 39296 T34 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> 39297 T54 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> 39296 T86 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> 39296 T41 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> 39643 T11 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52114_
   [junit4]   2> 39647 T11 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52114_
   [junit4]   2> 39654 T70 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 39657 T41 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 39658 T41 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 39659 T86 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 39658 T34 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 39660 T34 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 39659 T86 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 39660 T54 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 39662 T54 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 39667 T70 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 39691 T87 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 39692 T87 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 39701 T87 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 40829 T35 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 40832 T35 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52114_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52114"}
   [junit4]   2> 40832 T35 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 40833 T35 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 40852 T70 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> 40853 T41 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> 40853 T86 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> 40853 T54 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> 40852 T34 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> 41712 T87 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 41713 T87 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-jetty3-1379509770275/collection1
   [junit4]   2> 41713 T87 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 41716 T87 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 41716 T87 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 41720 T87 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty3-1379509770275/collection1/'
   [junit4]   2> 41721 T87 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-1379509770275/collection1/lib/classes/' to classloader
   [junit4]   2> 41722 T87 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-1379509770275/collection1/lib/README' to classloader
   [junit4]   2> 41869 T87 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 42039 T87 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 42043 T87 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 42162 T87 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 43659 T87 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 43667 T87 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 43674 T87 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 43688 T87 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 43807 T87 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 43808 T87 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-jetty3-1379509770275/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty3/
   [junit4]   2> 43808 T87 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@74d0d91c
   [junit4]   2> 43810 T87 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty3
   [junit4]   2> 43811 T87 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty3/index/
   [junit4]   2> 43812 T87 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 43818 T87 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty3/index
   [junit4]   2> 43819 T87 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=39, maxMergeAtOnceExplicit=49, maxMergedSegmentMB=95.8388671875, floorSegmentMB=0.4375, forceMergeDeletesPctAllowed=1.9355945343415182, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 43821 T87 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@46db97c0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@49e30132),segFN=segments_1,generation=1}
   [junit4]   2> 43822 T87 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 43838 T87 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 43843 T87 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 43844 T87 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 43844 T87 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 43845 T87 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 43846 T87 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 43847 T87 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 43848 T87 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 43849 T87 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 43851 T87 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 43854 T87 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 43855 T87 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 43856 T87 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 43858 T87 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 43859 T87 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 43878 T87 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 43886 T87 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 43887 T87 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 43890 T87 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=616193555, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 43891 T87 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@46db97c0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@49e30132),segFN=segments_1,generation=1}
   [junit4]   2> 43892 T87 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 43892 T87 oass.SolrIndexSearcher.<init> Opening Searcher@528461e6 main
   [junit4]   2> 43919 T88 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@528461e6 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 43927 T87 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 43928 T87 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52114 collection:collection1 shard:shard1
   [junit4]   2> 43928 T87 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 43972 T87 oasc.ZkController.register We are http://127.0.0.1:52114/collection1/ and leader is http://127.0.0.1:52108/collection1/
   [junit4]   2> 43973 T87 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52114
   [junit4]   2> 43973 T87 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 43974 T87 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> 43986 T87 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 43993 T11 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 43994 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 43996 T11 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> ASYNC  NEW_CORE C0 name=collection1 org.apache.solr.core.SolrCore@1fc2899d url=http://127.0.0.1:52114/collection1 node=127.0.0.1:52114_ C0_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:52114_, base_url=http://127.0.0.1:52114}
   [junit4]   2> 44007 T89 C0 P52114 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 44016 T89 C0 P52114 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 44017 T89 C0 P52114 oasc.ZkController.publish publishing core=collection1 state=recovering
   [junit4]   2> 44019 T89 C0 P52114 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 44024 T89 C0 P52114 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 44608 T11 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 44620 T11 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52117
   [junit4]   2> 44622 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 44623 T11 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 44623 T11 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-jetty4-1379509776474
   [junit4]   2> 44624 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty4-1379509776474/'
   [junit4]   2> 44703 T11 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-jetty4-1379509776474/solr.xml
   [junit4]   2> 44877 T11 oasc.CoreContainer.<init> New CoreContainer 1838767084
   [junit4]   2> 44878 T11 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-jetty4-1379509776474/]
   [junit4]   2> 44881 T11 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 44883 T11 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 44884 T11 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 44884 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 44885 T11 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 44886 T11 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 44887 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 44887 T11 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 44888 T11 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 44889 T11 oascsi.HttpClientUtil.createClient Creating new http cl

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

 ./org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty4
   [junit4]   2> 100624 T11 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty4/index;done=false>>]
   [junit4]   2> 100624 T11 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-1379509736572/jetty4/index
   [junit4]   2> 100625 T11 oasc.SolrCore.close [collection1_shard1_0_replica2]  CLOSING SolrCore org.apache.solr.core.SolrCore@7c077f8e
   [junit4]   2> 100641 T178 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 100643 T178 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node4",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52117_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52117"}
   [junit4]   2> 100646 T11 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=3,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=60,cumulative_deletesById=21,cumulative_deletesByQuery=0,cumulative_errors=0}
   [junit4]   2> 100648 T11 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 100649 T11 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 100650 T11 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 100655 T11 oasc.SolrCore.closeSearcher [collection1_shard1_0_replica2] Closing main searcher on request.
   [junit4]   2> 100656 T11 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 100657 T11 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-jetty4-1379509776474/collection1_shard1_0_replica2/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-jetty4-1379509776474/collection1_shard1_0_replica2/data;done=false>>]
   [junit4]   2> 100657 T11 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-jetty4-1379509776474/collection1_shard1_0_replica2/data
   [junit4]   2> 100656 T178 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node7",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":"shard1_0",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1_shard1_0_replica2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52117_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52117"}
   [junit4]   2> 100658 T11 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-jetty4-1379509776474/collection1_shard1_0_replica2/data/index.20130918111009914 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-jetty4-1379509776474/collection1_shard1_0_replica2/data/index.20130918111009914;done=false>>]
   [junit4]   2> 100659 T11 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-jetty4-1379509776474/collection1_shard1_0_replica2/data/index.20130918111009914
   [junit4]   2> 100670 T103 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 100670 T103 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 100671 T103 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 100673 T159 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 100673 T159 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 0)
   [junit4]   2> 100687 T11 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
   [junit4]   2> 100765 T11 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
   [junit4]   2> 100773 T11 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:52100 52100
   [junit4]   2> 100990 T159 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@20c7c08f name:ZooKeeperConnection Watcher:127.0.0.1:52100/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
   [junit4]   2> 100991 T159 oascc.ConnectionManager.process Client->ZooKeeper status change trigger but we are already closed
   [junit4]   2> 101003 T11 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 52104
   [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-1379509736572 FAILED !!!!!
   [junit4]   2> 101004 T11 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
   [junit4]   2> 101004 T11 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:52100 52100
   [junit4]   1>        /solr/collections/control_collection/leader_elect/shard1/election/90407550129537027-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:52104_",
   [junit4]   1>            "base_url":"http://127.0.0.1:52104"}
   [junit4]   1>   /solr/overseer_elect (2)
   [junit4]   1>    /solr/overseer_elect/election (5)
   [junit4]   1>     /solr/overseer_elect/election/90407550129537034-127.0.0.1:52114_-n_0000000003 (0)
   [junit4]   1>     /solr/overseer_elect/election/90407550129537032-127.0.0.1:52111_-n_0000000002 (0)
   [junit4]   1>     /solr/overseer_elect/election/90407550129537027-127.0.0.1:52104_-n_0000000000 (0)
   [junit4]   1>     /solr/overseer_elect/election/90407550129537030-127.0.0.1:52108_-n_0000000001 (0)
   [junit4]   1>     /solr/overseer_elect/election/90407550129537036-127.0.0.1:52117_-n_0000000004 (0)
   [junit4]   1>    /solr/overseer_elect/leader (0)
   [junit4]   1>    DATA:
   [junit4]   1>        {"id":"90407550129537027-127.0.0.1:52104_-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=CE2A9D393E9CE374 -Dtests.slow=true -Dtests.locale=et_EE -Dtests.timezone=Atlantic/South_Georgia -Dtests.file.encoding=UTF-8
   [junit4] FAILURE 97.1s | ShardSplitTest.testDistribSearch <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: Wrong doc count on shard1_1 expected:<81> but was:<70>
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([CE2A9D393E9CE374:4FCC132149C38348]:0)
   [junit4]    > 	at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:227)
   [junit4]    > 	at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:173)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:724)
   [junit4]   2> 101080 T11 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 98083 T10 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=Lucene3x, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=et_EE, timezone=Atlantic/South_Georgia
   [junit4]   2> NOTE: Mac OS X 10.8.4 x86_64/Oracle Corporation 1.7.0_40 (64-bit)/cpus=2,threads=1,free=18909248,total=56320000
   [junit4]   2> NOTE: All tests run in this JVM: [ShardSplitTest]
   [junit4] Completed in 102.56s, 1 test, 1 failure <<< FAILURES!

[...truncated 1014 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:402: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:382: 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/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:455: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1233: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:876: There were test failures: 327 suites, 1453 tests, 1 failure, 39 ignored (5 assumptions)

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



Mime
View raw message