You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/10/07 19:33:09 UTC

[JENKINS] Lucene-Solr-Tests-4.x-Java6 - Build # 2063 - Failure

Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/2063/

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

Error Message:
Test Setup Failure: shard1 should have just been set up to be inconsistent - but it's still consistent. Leader:http://127.0.0.1:24857/collection1 Dead Guy:http://127.0.0.1:24846/collection1skip list:[CloudJettyRunner [url=http://127.0.0.1:24853/collection1], CloudJettyRunner [url=http://127.0.0.1:24853/collection1]]

Stack Trace:
java.lang.AssertionError: Test Setup Failure: shard1 should have just been set up to be inconsistent - but it's still consistent. Leader:http://127.0.0.1:24857/collection1 Dead Guy:http://127.0.0.1:24846/collection1skip list:[CloudJettyRunner [url=http://127.0.0.1:24853/collection1], CloudJettyRunner [url=http://127.0.0.1:24853/collection1]]
	at __randomizedtesting.SeedInfo.seed([697FCBD7E6AF5B64:E89945CF91F03B58]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.junit.Assert.assertNotNull(Assert.java:526)
	at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:216)
	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:616)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:679)




Build Log:
[...truncated 9348 lines...]
   [junit4] Suite: org.apache.solr.cloud.SyncSliceTest
   [junit4]   2> 104111 T347 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 104115 T347 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-SyncSliceTest-1381165469423
   [junit4]   2> 104123 T347 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 104129 T348 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 104332 T347 oasc.ZkTestServer.run start zk server on port:24831
   [junit4]   2> 104715 T347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 104869 T354 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@46fde259 name:ZooKeeperConnection Watcher:127.0.0.1:24831 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 104869 T347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 104874 T347 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 105022 T347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 105035 T356 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@474b1500 name:ZooKeeperConnection Watcher:127.0.0.1:24831/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 105036 T347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 105044 T347 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 105049 T347 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 105053 T347 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 105057 T347 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 105061 T347 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 105062 T347 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 105075 T347 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 105076 T347 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 105183 T347 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 105184 T347 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 105189 T347 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 105189 T347 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 105194 T347 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 105195 T347 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 105199 T347 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 105200 T347 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 105205 T347 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 105206 T347 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 105210 T347 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 105211 T347 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 105219 T347 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 105220 T347 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 105232 T347 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 105233 T347 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 105550 T347 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 105555 T347 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:24834
   [junit4]   2> 105556 T347 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 105557 T347 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 105557 T347 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1381165470546
   [junit4]   2> 105558 T347 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1381165470546/'
   [junit4]   2> 105603 T347 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1381165470546/solr.xml
   [junit4]   2> 105681 T347 oasc.CoreContainer.<init> New CoreContainer 1201619962
   [junit4]   2> 105682 T347 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1381165470546/]
   [junit4]   2> 105684 T347 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 105685 T347 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 105685 T347 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 105686 T347 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 105686 T347 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 105687 T347 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 105687 T347 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 105688 T347 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 105688 T347 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 105689 T347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 105696 T347 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 105697 T347 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 105698 T347 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:24831/solr
   [junit4]   2> 105737 T347 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 105738 T347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 105742 T367 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@79569a45 name:ZooKeeperConnection Watcher:127.0.0.1:24831 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 105742 T347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 105761 T347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 105769 T347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 105772 T369 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@61bb1e3e name:ZooKeeperConnection Watcher:127.0.0.1:24831/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 105772 T347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 105789 T347 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 105808 T347 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 105834 T347 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 105837 T347 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:24834_
   [junit4]   2> 105847 T347 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:24834_
   [junit4]   2> 105853 T347 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 105892 T347 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 105897 T347 oasc.Overseer.start Overseer (id=90516060227043331-127.0.0.1:24834_-n_0000000000) starting
   [junit4]   2> 105937 T347 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 105961 T371 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 105962 T347 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 105966 T347 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 105970 T347 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 106013 T370 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 106037 T372 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 106038 T372 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 106041 T372 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 107526 T370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 107534 T370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:24834",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:24834_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 107535 T370 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 107573 T370 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 107606 T369 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> 108043 T372 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 108043 T372 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1381165470546/collection1
   [junit4]   2> 108044 T372 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 108045 T372 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 108045 T372 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 108048 T372 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1381165470546/collection1/'
   [junit4]   2> 108050 T372 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-controljetty-1381165470546/collection1/lib/README' to classloader
   [junit4]   2> 108051 T372 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-controljetty-1381165470546/collection1/lib/classes/' to classloader
   [junit4]   2> 108182 T372 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 108255 T372 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 108357 T372 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 108369 T372 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 109096 T372 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 109098 T372 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 109099 T372 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 109115 T372 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 109120 T372 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 109141 T372 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 109154 T372 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 109159 T372 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 109161 T372 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 109161 T372 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 109162 T372 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 109163 T372 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 109164 T372 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 109164 T372 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 109164 T372 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1381165470546/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1381165469423/control/data/
   [junit4]   2> 109165 T372 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@575c13ef
   [junit4]   2> 109166 T372 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1381165469423/control/data
   [junit4]   2> 109166 T372 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1381165469423/control/data/index/
   [junit4]   2> 109166 T372 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1381165469423/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 109167 T372 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1381165469423/control/data/index
   [junit4]   2> 109167 T372 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=26, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4149821854292428]
   [junit4]   2> 109168 T372 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@26e7ee9f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ffadfdf),segFN=segments_1,generation=1}
   [junit4]   2> 109169 T372 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 109172 T372 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 109173 T372 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 109173 T372 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 109174 T372 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 109174 T372 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 109174 T372 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 109175 T372 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 109175 T372 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 109176 T372 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 109176 T372 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 109177 T372 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 109177 T372 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 109178 T372 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 109178 T372 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 109179 T372 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 109194 T372 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 109202 T372 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 109202 T372 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 109203 T372 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=24.4443359375, floorSegmentMB=1.9970703125, forceMergeDeletesPctAllowed=1.1842228420442402, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 109204 T372 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@26e7ee9f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ffadfdf),segFN=segments_1,generation=1}
   [junit4]   2> 109204 T372 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 109205 T372 oass.SolrIndexSearcher.<init> Opening Searcher@783096a1 main
   [junit4]   2> 109208 T373 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@783096a1 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 109209 T372 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 109210 T372 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:24834 collection:control_collection shard:shard1
   [junit4]   2> 109227 T372 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 109238 T372 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 109267 T372 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 109271 T372 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 109271 T372 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 109279 T372 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:24834/collection1/
   [junit4]   2> 109280 T372 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 109280 T372 oasc.SyncStrategy.syncToMe http://127.0.0.1:24834/collection1/ has no replicas
   [junit4]   2> 109280 T372 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:24834/collection1/ shard1
   [junit4]   2> 109281 T372 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 110617 T370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 110649 T369 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> 110667 T372 oasc.ZkController.register We are http://127.0.0.1:24834/collection1/ and leader is http://127.0.0.1:24834/collection1/
   [junit4]   2> 110667 T372 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:24834
   [junit4]   2> 110667 T372 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 110668 T372 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 110668 T372 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 110671 T372 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 110672 T347 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
   [junit4]   2> 110673 T347 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 110674 T347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 110691 T347 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 110699 T347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 110702 T376 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b8195b3 name:ZooKeeperConnection Watcher:127.0.0.1:24831/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 110702 T347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 110705 T347 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 110711 T347 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 111012 T347 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 111022 T347 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:24846
   [junit4]   2> 111023 T347 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 111023 T347 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 111024 T347 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1381165476018
   [junit4]   2> 111024 T347 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1381165476018/'
   [junit4]   2> 111063 T347 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1381165476018/solr.xml
   [junit4]   2> 111142 T347 oasc.CoreContainer.<init> New CoreContainer 1963378559
   [junit4]   2> 111143 T347 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1381165476018/]
   [junit4]   2> 111145 T347 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 111145 T347 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 111146 T347 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 111146 T347 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 111147 T347 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 111147 T347 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 111148 T347 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 111148 T347 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 111149 T347 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 111149 T347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 111156 T347 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 111157 T347 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 111157 T347 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:24831/solr
   [junit4]   2> 111158 T347 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 111159 T347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 111162 T387 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10139edf name:ZooKeeperConnection Watcher:127.0.0.1:24831 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 111164 T347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 111172 T347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 111174 T347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 111176 T389 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4645801a name:ZooKeeperConnection Watcher:127.0.0.1:24831/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 111177 T347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 111190 T347 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 112159 T370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 112161 T370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:24834",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:24834_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 112176 T389 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> 112176 T376 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> 112176 T369 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> 112195 T347 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:24846_
   [junit4]   2> 112198 T347 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:24846_
   [junit4]   2> 112202 T376 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 112202 T389 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 112202 T369 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 112218 T390 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 112218 T390 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 112220 T390 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 113684 T370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 113685 T370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:24846",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:24846_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 113686 T370 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 113686 T370 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 113702 T369 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> 113702 T389 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> 113702 T376 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> 114223 T390 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 114223 T390 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1381165476018/collection1
   [junit4]   2> 114224 T390 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 114225 T390 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 114225 T390 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 114227 T390 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1381165476018/collection1/'
   [junit4]   2> 114229 T390 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty1-1381165476018/collection1/lib/README' to classloader
   [junit4]   2> 114229 T390 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty1-1381165476018/collection1/lib/classes/' to classloader
   [junit4]   2> 114292 T390 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 114353 T390 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 114455 T390 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 114465 T390 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 115097 T390 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 115097 T390 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 115099 T390 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 115112 T390 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 115117 T390 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 115139 T390 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 115144 T390 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 115149 T390 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 115151 T390 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 115151 T390 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 115152 T390 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 115153 T390 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 115154 T390 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 115154 T390 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 115154 T390 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1381165476018/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1381165469423/jetty1/
   [junit4]   2> 115155 T390 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@575c13ef
   [junit4]   2> 115156 T390 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1381165469423/jetty1
   [junit4]   2> 115156 T390 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1381165469423/jetty1/index/
   [junit4]   2> 115157 T390 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1381165469423/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 115157 T390 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1381165469423/jetty1/index
   [junit4]   2> 115158 T390 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=26, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4149821854292428]
   [junit4]   2> 115159 T390 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@458d1a4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba8be19),segFN=segments_1,generation=1}
   [junit4]   2> 115159 T390 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 115163 T390 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 115164 T390 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 115164 T390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 115164 T390 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 115165 T390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 115165 T390 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 115166 T390 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 115166 T390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 115166 T390 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 115167 T390 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 115168 T390 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 115168 T390 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 115169 T390 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 115169 T390 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 115170 T390 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 115179 T390 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 115183 T390 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 115184 T390 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 115185 T390 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=24.4443359375, floorSegmentMB=1.9970703125, forceMergeDeletesPctAllowed=1.1842228420442402, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 115185 T390 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@458d1a4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba8be19),segFN=segments_1,generation=1}
   [junit4]   2> 115186 T390 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 115186 T390 oass.SolrIndexSearcher.<init> Opening Searcher@31431174 main
   [junit4]   2> 115191 T391 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@31431174 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 115193 T390 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 115193 T390 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:24846 collection:collection1 shard:shard1
   [junit4]   2> 115194 T390 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 115196 T390 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 115215 T390 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 115227 T390 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 115227 T390 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 115227 T390 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:24846/collection1/
   [junit4]   2> 115228 T390 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 115228 T390 oasc.SyncStrategy.syncToMe http://127.0.0.1:24846/collection1/ has no replicas
   [junit4]   2> 115228 T390 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:24846/collection1/ shard1
   [junit4]   2> 115229 T390 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 116719 T370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 116770 T369 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> 116770 T389 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> 116770 T376 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> 116820 T390 oasc.ZkController.register We are http://127.0.0.1:24846/collection1/ and leader is http://127.0.0.1:24846/collection1/
   [junit4]   2> 116820 T390 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:24846
   [junit4]   2> 116820 T390 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 116821 T390 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 116821 T390 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 116824 T390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 116825 T347 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
   [junit4]   2> 116826 T347 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 116826 T347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 117097 T347 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 117100 T347 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:24853
   [junit4]   2> 117101 T347 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 117101 T347 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 117102 T347 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1381165482135
   [junit4]   2> 117102 T347 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1381165482135/'
   [junit4]   2> 117140 T347 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1381165482135/solr.xml
   [junit4]   2> 117214 T347 oasc.CoreContainer.<init> New CoreContainer 649102502
   [junit4]   2> 117215 T347 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1381165482135/]
   [junit4]   2> 117217 T347 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 117217 T347 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 117218 T347 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 117218 T347 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 117219 T347 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 117219 T347 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 117220 T347 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 117220 T347 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 117221 T347 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 117221 T347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 117228 T347 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 117229 T347 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 117229 T347 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:24831/solr
   [junit4]   2> 117230 T347 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 117231 T347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 117234 T403 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ed4c222 name:ZooKeeperConnection Watcher:127.0.0.1:24831 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 117235 T347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 117238 T347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 117240 T347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 117247 T405 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e50867d name:ZooKeeperConnection Watcher:127.0.0.1:24831/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 117247 T347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 117254 T347 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 118260 T347 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:24853_
   [junit4]   2> 118267 T347 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:24853_
   [junit4]   2> 118271 T369 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 118272 T376 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 118272 T405 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 118271 T389 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 118285 T370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 118286 T370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:24846",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:24846_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 118289 T406 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 118289 T406 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 118298 T406 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 118299 T370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:24853",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:24853_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 118300 T370 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 118300 T370 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 118312 T369 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> 118312 T376 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> 118312 T389 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> 118312 T405 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> 119299 T406 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 119299 T406 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1381165482135/collection1
   [junit4]   2> 119300 T406 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 119301 T406 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 119301 T406 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 119303 T406 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1381165482135/collection1/'
   [junit4]   2> 119305 T406 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty2-1381165482135/collection1/lib/classes/' to classloader
   [junit4]   2> 119306 T406 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty2-1381165482135/collection1/lib/README' to classloader
   [junit4]   2> 119375 T406 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 119445 T406 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 119548 T406 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 119559 T406 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 120195 T406 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 120196 T406 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 120197 T406 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 120206 T406 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 120209 T406 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 120227 T406 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 120232 T406 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 120236 T406 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 120237 T406 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 120238 T406 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 120238 T406 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 120239 T406 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 120240 T406 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 120240 T406 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 120240 T406 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1381165482135/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1381165469423/jetty2/
   [junit4]   2> 120240 T406 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@575c13ef
   [junit4]   2> 120241 T406 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1381165469423/jetty2
   [junit4]   2> 120242 T406 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1381165469423/jetty2/index/
   [junit4]   2> 120242 T406 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1381165469423/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 120242 T406 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1381165469423/jetty2/index
   [junit4]   2> 120242 T406 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=26, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4149821854292428]
   [junit4]   2> 120243 T406 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7f42ea9b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@a4ecedd),segFN=segments_1,generation=1}
   [junit4]   2> 120243 T406 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 120247 T406 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 120247 T406 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 120247 T406 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 120247 T406 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 120248 T406 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 120248 T406 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 120248 T406 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 120249 T406 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 120249 T406 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 120249 T406 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 120250 T406 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 120250 T406 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 120251 T406 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 120251 T406 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 120251 T406 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 120258 T406 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 120261 T406 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 120262 T406 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 120262 T406 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=24.4443359375, floorSegmentMB=1.9970703125, forceMergeDeletesPctAllowed=1.1842228420442402, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 120263 T406 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7f42ea9b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@a4ecedd),segFN=segments_1,generation=1}
   [junit4]   2> 120263 T406 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 120263 T406 oass.SolrIndexSearcher.<init> Opening Searcher@5956d3a9 main
   [junit4]   2> 120267 T407 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5956d3a9 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 120270 T406 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 120270 T406 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:24853 collection:collection1 shard:shard1
   [junit4]   2> 120271 T406 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 120280 T406 oasc.ZkController.register We are http://127.0.0.1:24853/collection1/ and leader is http://127.0.0.1:24846/collection1/
   [junit4]   2> 120280 T406 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:24853
   [junit4]   2> 120281 T406 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 120281 T406 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C50 name=collection1 org.apache.solr.core.SolrCore@1f769f17 url=http://127.0.0.1:24853/collection1 node=127.0.0.1:24853_ C50_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:24853, core=collection1, node_name=127.0.0.1:24853_}
   [junit4]   2> 120289 T408 C50 P24853 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 120289 T406 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 120289 T408 C50 P24853 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 120290 T408 C50 P24853 oasc.ZkController.publish publishing core=collection1 state=recovering
   [junit4]   2> 120290 T408 C50 P24853 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 120291 T347 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
   [junit4]   2> 120291 T347 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 120292 T347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 120292 T408 C50 P24853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 120305 T379 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true
   [junit4]   2> 120475 T347 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 120477 T347 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:24857
   [junit4]   2> 120478 T347 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 120478 T347 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 120478 T347 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.SyncSliceTest-jetty3-1381165485600
   [junit4]   2> 120479 T347 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-jetty3-1381165485600/'
   [junit4]   2> 120503 T347 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1381165485600/solr.xml
   [junit4]   2> 120552 T347 oasc.CoreContainer.<init> New CoreContainer 1678074440
   [junit4]   2> 120552 T347 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.SyncSliceTest-jetty3-1381165485600/]
   [junit4]   2> 120554 T347 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 120554 T347 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 120554 T347 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 120555 T347 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 120555 T347 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 120555 T347 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 120556 T347 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 120556 T347 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 120556 T347 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 120557 T347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 120561 T347 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 120562 T347 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 120562 T347 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:24831/solr
   [junit4]   2> 120562 T347 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 120563 T347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 120591 T420 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d779845 name:ZooKeeperConnection Watcher:127.0.0.1:24831 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 120592 T347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 120594 T347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 120595 T347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 120605 T422 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b1fff2b name:ZooKeeperConnection Watcher:127.0.0.1:24831/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 120606 T347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 120612 T347 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 121326 T370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 121327 T370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:24853",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:24853_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 121374 T422 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> 121374 T376 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> 121374 T389 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> 121374 T405 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> 121374 T369 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> 121616 T347 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:24857_
   [junit4]   2> 121619 T347 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:24857_
   [junit4]   2> 121623 T405 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 121623 T376 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 121623 T389 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 121623 T369 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 121623 T422 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 121638 T423 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 121639 T423 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 121641 T423 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 122308 T379 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
   [junit4]   2> 122309 T379 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=core_node2&state=recovering&nodeName=127.0.0.1:24853_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2003 
   [junit4]   2> 122881 T370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 122883 T370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:24857",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:24857_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node3"}
   [junit4]   2> 122883 T370 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 122884 T370 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 122902 T422 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> 122902 T376 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> 122902 T389 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> 122902 T405 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> 122902 T369 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> 123643 T423 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 123643 T423 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.SyncSliceTest-jetty3-1381165485600/collection1
   [junit4]   2> 123644 T423 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 123645 T423 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 123645 T423 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 123647 T423 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-jetty3-1381165485600/collection1/'
   [junit4]   2> 123648 T423 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty3-1381165485600/collection1/lib/classes/' to classloader
   [junit4]   2> 123649 T423 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty3-1381165485600/collection1/lib/README' to classloader
   [junit4]   2> 123711 T423 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 123772 T423 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 123873 T423 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 123884 T423 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> ASYNC  NEW_CORE C51 name=collection1 org.apache.solr.core.SolrCore@1f769f17 url=http://127.0.0.1:24853/collection1 node=127.0.0.1:24853_ C51_STATE=coll:collection1 core:collection1 props:{state=recovering, base_url=http://127.0.0.1:24853, core=collection1, node_name=127.0.0.1:24853_}
   [junit4]   2> 124311 T408 C51 P24853 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:24846/collection1/ core=collection1 - recoveringAfterStartup=true
   [junit4]   2> 124326 T408 C51 P24853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 124340 T408 C51 P24853 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:24853 START replicas=[http://127.0.0.1:24846/collection1/] nUpdates=100
   [junit4]   2> 124340 T408 C51 P24853 oasu.PeerSync.sync WARN no frame of reference to tell if we've missed updates
   [junit4]   2> 124341 T408 C51 P24853 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
   [junit4]   2> 124342 T408 C51 P24853 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
   [junit4]   2> 124342 T408 C51 P24853 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
   [junit4]   2> 124342 T408 C51 P24853 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
   [junit4]   2> 124343 T408 C51 P24853 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:24846/collection1/. core=collection1
   [junit4]   2> 124343 T408 C51 P24853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> ASYNC  NEW_CORE C52 name=collection1 org.apache.solr.core.SolrCore@123b6177 url=http://127.0.0.1:24846/collection1 node=127.0.0.1:24846_ C52_STATE=coll:collection1 core:collection1 props:{state=active, base_url=http://127.0.0.1:24846, core=collection1, node_name=127.0.0.1:24846_, leader=true}
   [junit4]   2> 124352 T380 C52 P24846 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0 
   [junit4]   2> 124393 T381 C52 P24846 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 124393 T381 C52 P24846 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 124394 T381 C52 P24846 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 124394 T381 C52 P24846 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 39
   [junit4]   2> 124483 T408 C51 P24853 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 124484 T408 C51 P24853 oascsi.HttpClientUtil.createClient Creating new http client, config:connTimeout=5000&socketTimeout=20000&allowCompression=false&maxConnections=10000&maxConnectionsPerHost=10000
   [junit4]   2> 124501 T408 C51 P24853 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
   [junit4]   2> 124505 T382 C52 P24846 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 124506 T382 C52 P24846 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2 
   [junit4]   2> 124507 T408 C51 P24853 oasc.RecoveryStrategy.replay No replay needed. core=collection1
   [junit4]   2> 124507 T408 C51 P24853 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
   [junit4]   2> 124507 T408 C51 P24853 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 124508 T408 C51 P24853 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 124510 T408 C51 P24853 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
   [junit4]   2> 124674 T423 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 124675 T423 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 124676 T423 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 124691 T423 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 124695 T423 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 124723 T423 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 124744 T423 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 124750 T423 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 124751 T423 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 124752 T423 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 124752 T423 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 124754 T423 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 124754 T423 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 124755 T423 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 124755 T423 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.SyncSliceTest-jetty3-1381165485600/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1381165469423/jetty3/
   [junit4]   2> 124755 T423 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@575c13ef
   [junit4]   2> 124756 T423 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1381165469423/jetty3
   [junit4]   2> 124757 T423 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1381165469423/jetty3/index/
   [junit4]   2> 124757 T423 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1381165469423/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 124757 T423 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1381165469423/jetty3/index
   [junit4]   2> 124758 T423 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=26, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4149821854292428]
   [junit4]   2> 124759 T423 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@603caedf lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@430eaae5),segFN=segments_1,generation=1}
   [junit4]   2> 124759 T423 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 124764 T423 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 124765 T423 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 124765 T423 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 124766 T423 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain

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

           "state":"active",
   [junit4]   1>                   "base_url":"http://127.0.0.1:24853",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "node_name":"127.0.0.1:24853_"},
   [junit4]   1>                 "core_node3":{
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "base_url":"http://127.0.0.1:24857",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "node_name":"127.0.0.1:24857_",
   [junit4]   1>                   "leader":"true"},
   [junit4]   1>                 "core_node4":{
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "base_url":"http://127.0.0.1:24867",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "node_name":"127.0.0.1:24867_"}}}},
   [junit4]   1>           "maxShardsPerNode":"1",
   [junit4]   1>           "router":{"name":"compositeId"},
   [junit4]   1>           "replicationFactor":"1"},
   [junit4]   1>         "control_collection":{
   [junit4]   1>           "shards":{"shard1":{
   [junit4]   1>               "range":"80000000-7fffffff",
   [junit4]   1>               "state":"active",
   [junit4]   1>               "replicas":{"core_node1":{
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "base_url":"http://127.0.0.1:24834",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "node_name":"127.0.0.1:24834_",
   [junit4]   1>                   "leader":"true"}}}},
   [junit4]   1>           "maxShardsPerNode":"1",
   [junit4]   1>           "router":{"name":"compositeId"},
   [junit4]   1>           "replicationFactor":"1"}}
   [junit4]   1>   /solr/aliases.json (0)
   [junit4]   1>   /solr/live_nodes (5)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:24846_ (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:24834_ (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:24867_ (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:24853_ (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:24857_ (0)
   [junit4]   1>   /solr/overseer (3)
   [junit4]   1>   DATA:
   [junit4]   1>       
   [junit4]   1>    /solr/overseer/queue (0)
   [junit4]   1>    /solr/overseer/queue-work (0)
   [junit4]   1>    /solr/overseer/collection-queue-work (0)
   [junit4]   1>   /solr/collections (2)
   [junit4]   1>    /solr/collections/collection1 (3)
   [junit4]   1>    DATA:
   [junit4]   1>        {"configName":"conf1"}
   [junit4]   1>     /solr/collections/collection1/shards (0)
   [junit4]   1>     /solr/collections/collection1/leader_elect (1)
   [junit4]   1>      /solr/collections/collection1/leader_elect/shard1 (1)
   [junit4]   1>       /solr/collections/collection1/leader_elect/shard1/election (4)
   [junit4]   1>        /solr/collections/collection1/leader_elect/shard1/election/90516060227043336-core_node2-n_0000000004 (0)
   [junit4]   1>        /solr/collections/collection1/leader_elect/shard1/election/90516060227043338-core_node3-n_0000000002 (0)
   [junit4]   1>        /solr/collections/collection1/leader_elect/shard1/election/90516060227043340-core_node4-n_0000000003 (0)
   [junit4]   1>        /solr/collections/collection1/leader_elect/shard1/election/90516060227043342-core_node1-n_0000000005 (0)
   [junit4]   1>     /solr/collections/collection1/leaders (1)
   [junit4]   1>      /solr/collections/collection1/leaders/shard1 (0)
   [junit4]   1>      DATA:
   [junit4]   1>          {
   [junit4]   1>            "core":"collection1",
   [junit4]   1>            "node_name":"127.0.0.1:24857_",
   [junit4]   1>            "base_url":"http://127.0.0.1:24857"}
   [junit4]   1>    /solr/collections/control_collection (3)
   [junit4]   1>    DATA:
   [junit4]   1>        {"configName":"conf1"}
   [junit4]   1>     /solr/collections/control_collection/shards (0)
   [junit4]   1>     /solr/collections/control_collection/leader_elect (1)
   [junit4]   1>      /solr/collections/control_collection/leader_elect/shard1 (1)
   [junit4]   1>       /solr/collections/control_collection/leader_elect/shard1/election (1)
   [junit4]   1>        /solr/collections/control_collection/leader_elect/shard1/election/90516060227043331-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:24834_",
   [junit4]   1>            "base_url":"http://127.0.0.1:24834"}
   [junit4]   1>   /solr/overseer_elect (2)
   [junit4]   1>    /solr/overseer_elect/election (5)
   [junit4]   1>     /solr/overseer_elect/election/90516060227043336-127.0.0.1:24853_-n_0000000002 (0)
   [junit4]   1>     /solr/overseer_elect/election/90516060227043342-127.0.0.1:24846_-n_0000000005 (0)
   [junit4]   1>     /solr/overseer_elect/election/90516060227043340-127.0.0.1:24867_-n_0000000004 (0)
   [junit4]   1>     /solr/overseer_elect/election/90516060227043338-127.0.0.1:24857_-n_0000000003 (0)
   [junit4]   1>     /solr/overseer_elect/election/90516060227043331-127.0.0.1:24834_-n_0000000000 (0)
   [junit4]   1>    /solr/overseer_elect/leader (0)
   [junit4]   1>    DATA:
   [junit4]   1>        {"id":"90516060227043331-127.0.0.1:24834_-n_0000000000"}
   [junit4]   1>  /zookeeper (1)
   [junit4]   1>  DATA:
   [junit4]   1>      
   [junit4]   1> 
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=SyncSliceTest -Dtests.method=testDistribSearch -Dtests.seed=697FCBD7E6AF5B64 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=tr_TR -Dtests.timezone=America/Dawson_Creek -Dtests.file.encoding=UTF-8
   [junit4] FAILURE  117s J0 | SyncSliceTest.testDistribSearch <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: Test Setup Failure: shard1 should have just been set up to be inconsistent - but it's still consistent. Leader:http://127.0.0.1:24857/collection1 Dead Guy:http://127.0.0.1:24846/collection1skip list:[CloudJettyRunner [url=http://127.0.0.1:24853/collection1], CloudJettyRunner [url=http://127.0.0.1:24853/collection1]]
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([697FCBD7E6AF5B64:E89945CF91F03B58]:0)
   [junit4]    > 	at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:216)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:679)
   [junit4]   2> 221334 T347 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 117229 T346 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
   [junit4]   2> 222299 T440 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Lucene45: {range_facet_l=PostingsFormat(name=Memory doPackFST= false), text=PostingsFormat(name=SimpleText), _version_=PostingsFormat(name=Direct), rnd_b=PostingsFormat(name=NestedPulsing), intDefault=PostingsFormat(name=Direct), id=PostingsFormat(name=NestedPulsing), timestamp=PostingsFormat(name=Memory doPackFST= false), a_t=PostingsFormat(name=Memory doPackFST= false), range_facet_sl=PostingsFormat(name=NestedPulsing), range_facet_si=PostingsFormat(name=Memory doPackFST= false), other_tl1=PostingsFormat(name=Direct), multiDefault=PostingsFormat(name=Memory doPackFST= false), a_si=PostingsFormat(name=Direct)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=tr_TR, timezone=America/Dawson_Creek
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=1,free=209338408,total=481689600
   [junit4]   2> NOTE: All tests run in this JVM: [CoreAdminCreateDiscoverTest, SampleTest, TestSurroundQueryParser, AnalysisAfterCoreReloadTest, ExternalFileFieldSortTest, BadComponentTest, CoreMergeIndexesAdminHandlerTest, CopyFieldTest, EchoParamsTest, TestPHPSerializedResponseWriter, TestSort, TestSolrIndexConfig, QueryEqualityTest, TestShardHandlerFactory, SimpleFacetsTest, DateMathParserTest, TestBadConfig, UpdateRequestProcessorFactoryTest, SuggesterFSTTest, TestPerFieldSimilarity, TestNRTOpen, TestConfig, TestElisionMultitermQuery, TestCoreContainer, DistributedTermsComponentTest, TestExtendedDismaxParser, TestPostingsSolrHighlighter, DOMUtilTest, TestBM25SimilarityFactory, SystemInfoHandlerTest, MoreLikeThisHandlerTest, SyncSliceTest]
   [junit4] Completed on J0 in 118.25s, 1 test, 1 failure <<< FAILURES!

[...truncated 827 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:428: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:408: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/common-build.xml:451: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:1233: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:876: There were test failures: 327 suites, 1453 tests, 1 failure, 34 ignored (6 assumptions)

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