lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-4.x-Linux (32bit/ibm-j9-jdk7) - Build # 10326 - Failure!
Date Sun, 01 Jun 2014 16:51:36 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/10326/
Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}

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

Error Message:
No live SolrServers available to handle this request

Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request
	at __randomizedtesting.SeedInfo.seed([ADD85D71DFA185F3:2C3ED369A8FEE5CF]:0)
	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:317)
	at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:650)
	at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91)
	at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1149)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1118)
	at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:236)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:94)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:619)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
	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:65)
	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:360)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
	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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	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:65)
	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:360)
	at java.lang.Thread.run(Thread.java:853)




Build Log:
[...truncated 11254 lines...]
   [junit4] Suite: org.apache.solr.cloud.SyncSliceTest
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/init-core-data-001
   [junit4]   2> 1329624 T4614 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
   [junit4]   2> 1329625 T4614 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /p_w/jf
   [junit4]   2> 1329627 T4614 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 1329628 T4614 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1329629 T4615 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1329728 T4614 oasc.ZkTestServer.run start zk server on port:50034
   [junit4]   2> 1329730 T4614 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1334849 T4618 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 5118ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 1334849 T4621 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@31dbb550 name:ZooKeeperConnection Watcher:127.0.0.1:50034 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1334850 T4614 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1334851 T4614 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1334854 T4614 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1334855 T4623 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5f2bed37 name:ZooKeeperConnection Watcher:127.0.0.1:50034/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1334855 T4614 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1334856 T4614 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1334858 T4614 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1334860 T4614 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1334862 T4614 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1334864 T4614 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1334865 T4614 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1334871 T4614 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 1334872 T4614 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1334875 T4614 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1334876 T4614 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1334879 T4614 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1334880 T4614 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1334882 T4614 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1334883 T4614 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1334885 T4614 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1334886 T4614 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1334888 T4614 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 1334889 T4614 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 1334891 T4614 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1334892 T4614 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1334894 T4614 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1334895 T4614 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1334898 T4614 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1334899 T4614 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1334902 T4614 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1334903 T4614 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1335181 T4614 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1335186 T4614 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:38126
   [junit4]   2> 1335187 T4614 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1335187 T4614 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1335188 T4614 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-002
   [junit4]   2> 1335189 T4614 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-002/'
   [junit4]   2> 1335197 T4614 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-002/solr.xml
   [junit4]   2> 1335232 T4614 oasc.CoreContainer.<init> New CoreContainer -1919442265
   [junit4]   2> 1335233 T4614 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-002/]
   [junit4]   2> 1335234 T4614 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1335235 T4614 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1335235 T4614 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1335236 T4614 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1335236 T4614 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1335237 T4614 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1335238 T4614 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1335238 T4614 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1335239 T4614 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1335240 T4614 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1335240 T4614 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1335241 T4614 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1335241 T4614 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50034/solr
   [junit4]   2> 1335242 T4614 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1335243 T4614 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1335244 T4634 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d0c3bfa6 name:ZooKeeperConnection Watcher:127.0.0.1:50034 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1335244 T4614 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1335246 T4614 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1335247 T4636 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e83b2d4 name:ZooKeeperConnection Watcher:127.0.0.1:50034/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1335247 T4614 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1335250 T4614 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1335253 T4614 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1335255 T4614 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 1335257 T4614 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 1335259 T4614 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 1335276 T4614 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1335278 T4614 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38126_p_w%2Fjf
   [junit4]   2> 1335279 T4614 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38126_p_w%2Fjf
   [junit4]   2> 1335282 T4614 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1335283 T4614 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1335285 T4614 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38126_p_w%2Fjf
   [junit4]   2> 1335286 T4614 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1335287 T4614 oasc.Overseer.start Overseer (id=91857854379851779-127.0.0.1:38126_p_w%2Fjf-n_0000000000) starting
   [junit4]   2> 1335293 T4614 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1335299 T4638 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1335299 T4614 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1335301 T4614 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1335302 T4614 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1335304 T4637 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1335307 T4639 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 1335308 T4639 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1335308 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1335308 T4639 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1335309 T4637 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1335309 T4637 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:38126/p_w/jf",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:38126_p_w%2Fjf",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1335310 T4637 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 1335310 T4637 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1335312 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1335312 T4636 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> 1336309 T4639 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1336309 T4639 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 1336310 T4639 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1336310 T4639 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1336311 T4639 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1336311 T4639 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-002/collection1/'
   [junit4]   2> 1336312 T4639 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-002/collection1/lib/.svn/' to classloader
   [junit4]   2> 1336312 T4639 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-002/collection1/lib/classes/' to classloader
   [junit4]   2> 1336313 T4639 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-002/collection1/lib/README' to classloader
   [junit4]   2> 1336343 T4639 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
   [junit4]   2> 1336377 T4639 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1336378 T4639 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1336383 T4639 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1336703 T4639 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1336704 T4639 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1336704 T4639 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1336709 T4639 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1336711 T4639 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1336720 T4639 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1336723 T4639 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1336727 T4639 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1336728 T4639 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1336728 T4639 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1336728 T4639 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1336729 T4639 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1336729 T4639 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1336730 T4639 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 1336730 T4639 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1336730 T4639 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-002/collection1/, dataDir=./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-001/control/data/
   [junit4]   2> 1336730 T4639 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4c9adbd6
   [junit4]   2> 1336731 T4639 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-001/control/data
   [junit4]   2> 1336731 T4639 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-001/control/data/index/
   [junit4]   2> 1336732 T4639 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1336732 T4639 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-001/control/data/index
   [junit4]   2> 1336732 T4639 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=661686639, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 1336733 T4639 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@91b92e7b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7add8b69),segFN=segments_1,generation=1}
   [junit4]   2> 1336733 T4639 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1336735 T4639 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1336736 T4639 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1336736 T4639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1336736 T4639 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1336736 T4639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1336737 T4639 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1336737 T4639 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1336737 T4639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1336738 T4639 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1336738 T4639 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1336738 T4639 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1336739 T4639 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1336739 T4639 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1336739 T4639 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1336740 T4639 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1336740 T4639 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1336741 T4639 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1336744 T4639 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1336744 T4639 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1336745 T4639 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=48, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=45.462890625, floorSegmentMB=2.0537109375, forceMergeDeletesPctAllowed=27.528139899562554, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.523838025257952
   [junit4]   2> 1336746 T4639 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@91b92e7b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7add8b69),segFN=segments_1,generation=1}
   [junit4]   2> 1336746 T4639 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1336746 T4639 oass.SolrIndexSearcher.<init> Opening Searcher@f47e99e4[collection1] main
   [junit4]   2> 1336747 T4639 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1336748 T4639 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1336748 T4639 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1336748 T4639 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1336749 T4639 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1336749 T4639 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1336749 T4639 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1336750 T4639 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1336750 T4639 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 1336750 T4639 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1336752 T4640 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f47e99e4[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1336753 T4639 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1336754 T4643 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:38126/p_w/jf collection:control_collection shard:shard1
   [junit4]   2> 1336754 T4614 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 1336755 T4614 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1336754 T4643 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1336756 T4614 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1336757 T4645 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@aa268fa2 name:ZooKeeperConnection Watcher:127.0.0.1:50034/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1336758 T4614 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1336760 T4614 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1336762 T4643 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1336763 T4614 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 1336764 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1336765 T4643 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1336765 T4643 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1336765 T4637 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> ASYNC  NEW_CORE C2038 name=collection1 org.apache.solr.core.SolrCore@3f108c94 url=http://127.0.0.1:38126/p_w/jf/collection1 node=127.0.0.1:38126_p_w%2Fjf C2038_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:38126/p_w/jf, core=collection1, node_name=127.0.0.1:38126_p_w%2Fjf}
   [junit4]   2> 1336766 T4643 C2038 P38126 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:38126/p_w/jf/collection1/
   [junit4]   2> 1336766 T4643 C2038 P38126 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1336767 T4643 C2038 P38126 oasc.SyncStrategy.syncToMe http://127.0.0.1:38126/p_w/jf/collection1/ has no replicas
   [junit4]   2> 1336767 T4643 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:38126/p_w/jf/collection1/ shard1
   [junit4]   2> 1336768 T4643 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 1336768 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1336771 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1336774 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1336876 T4636 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> 1336876 T4645 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> 1336922 T4643 oasc.ZkController.register We are http://127.0.0.1:38126/p_w/jf/collection1/ and leader is http://127.0.0.1:38126/p_w/jf/collection1/
   [junit4]   2> 1336923 T4643 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38126/p_w/jf
   [junit4]   2> 1336923 T4643 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1336923 T4643 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 1336923 T4643 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1336925 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1336925 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1336925 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1336925 T4643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1336927 T4637 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1336928 T4637 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:38126/p_w/jf",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:38126_p_w%2Fjf",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1336930 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1337003 T4614 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 1337004 T4614 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1337006 T4614 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:45358
   [junit4]   2> 1337007 T4614 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1337007 T4614 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1337008 T4614 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-003
   [junit4]   2> 1337008 T4614 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-003/'
   [junit4]   2> 1337016 T4614 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-003/solr.xml
   [junit4]   2> 1337032 T4636 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> 1337032 T4645 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> 1337050 T4614 oasc.CoreContainer.<init> New CoreContainer -1146177598
   [junit4]   2> 1337050 T4614 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-003/]
   [junit4]   2> 1337051 T4614 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1337052 T4614 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1337052 T4614 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1337053 T4614 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1337053 T4614 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1337054 T4614 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1337054 T4614 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1337055 T4614 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1337055 T4614 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1337056 T4614 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1337057 T4614 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1337057 T4614 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1337058 T4614 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50034/solr
   [junit4]   2> 1337058 T4614 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1337059 T4614 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1337061 T4656 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@44cc6a90 name:ZooKeeperConnection Watcher:127.0.0.1:50034 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1337061 T4614 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1337063 T4614 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1337064 T4658 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@83ce7cb9 name:ZooKeeperConnection Watcher:127.0.0.1:50034/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1337065 T4614 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1337076 T4614 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1338078 T4614 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45358_p_w%2Fjf
   [junit4]   2> 1338080 T4614 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45358_p_w%2Fjf
   [junit4]   2> 1338081 T4645 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1338081 T4658 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1338081 T4636 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1338086 T4659 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 1338087 T4659 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1338087 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1338088 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1338088 T4659 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1338088 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1338089 T4637 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1338089 T4637 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:45358/p_w/jf",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:45358_p_w%2Fjf",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1338089 T4637 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 1338090 T4637 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1338091 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1338193 T4636 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> 1338193 T4645 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> 1338193 T4658 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> 1339088 T4659 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1339089 T4659 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1339090 T4659 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1339090 T4659 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1339091 T4659 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1339091 T4659 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-003/collection1/'
   [junit4]   2> 1339092 T4659 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-003/collection1/lib/.svn/' to classloader
   [junit4]   2> 1339093 T4659 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-003/collection1/lib/classes/' to classloader
   [junit4]   2> 1339093 T4659 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-003/collection1/lib/README' to classloader
   [junit4]   2> 1339140 T4659 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
   [junit4]   2> 1339197 T4659 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1339198 T4659 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1339207 T4659 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1339565 T4659 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1339566 T4659 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1339566 T4659 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1339571 T4659 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1339573 T4659 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1339582 T4659 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1339586 T4659 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1339590 T4659 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1339591 T4659 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1339591 T4659 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1339591 T4659 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1339592 T4659 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1339592 T4659 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1339593 T4659 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1339593 T4659 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1339593 T4659 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-003/collection1/, dataDir=./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-001/jetty1/
   [junit4]   2> 1339594 T4659 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4c9adbd6
   [junit4]   2> 1339595 T4659 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-001/jetty1
   [junit4]   2> 1339595 T4659 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-001/jetty1/index/
   [junit4]   2> 1339595 T4659 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 1339596 T4659 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-001/jetty1/index
   [junit4]   2> 1339596 T4659 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=661686639, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 1339597 T4659 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@ed1d8c22 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@46c778db),segFN=segments_1,generation=1}
   [junit4]   2> 1339597 T4659 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1339599 T4659 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1339600 T4659 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1339600 T4659 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1339600 T4659 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1339601 T4659 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1339601 T4659 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1339601 T4659 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1339602 T4659 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1339602 T4659 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1339603 T4659 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1339603 T4659 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1339603 T4659 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1339604 T4659 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1339604 T4659 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1339604 T4659 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1339605 T4659 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1339606 T4659 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1339608 T4659 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1339609 T4659 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1339609 T4659 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=48, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=45.462890625, floorSegmentMB=2.0537109375, forceMergeDeletesPctAllowed=27.528139899562554, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.523838025257952
   [junit4]   2> 1339610 T4659 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@ed1d8c22 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@46c778db),segFN=segments_1,generation=1}
   [junit4]   2> 1339610 T4659 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1339611 T4659 oass.SolrIndexSearcher.<init> Opening Searcher@7b6b6fc6[collection1] main
   [junit4]   2> 1339611 T4659 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1339612 T4659 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1339612 T4659 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1339613 T4659 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1339613 T4659 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1339613 T4659 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1339614 T4659 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1339614 T4659 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1339614 T4659 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 1339615 T4659 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1339617 T4660 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7b6b6fc6[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1339618 T4659 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1339619 T4663 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:45358/p_w/jf collection:collection1 shard:shard1
   [junit4]   2> 1339619 T4614 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 1339620 T4663 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1339620 T4614 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1339625 T4663 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1339627 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1339627 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1339627 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1339627 T4663 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1339628 T4663 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C2039 name=collection1 org.apache.solr.core.SolrCore@48beb320 url=http://127.0.0.1:45358/p_w/jf/collection1 node=127.0.0.1:45358_p_w%2Fjf C2039_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:45358/p_w/jf, core=collection1, node_name=127.0.0.1:45358_p_w%2Fjf}
   [junit4]   2> 1339628 T4663 C2039 P45358 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:45358/p_w/jf/collection1/
   [junit4]   2> 1339629 T4637 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1339629 T4663 C2039 P45358 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1339630 T4663 C2039 P45358 oasc.SyncStrategy.syncToMe http://127.0.0.1:45358/p_w/jf/collection1/ has no replicas
   [junit4]   2> 1339630 T4663 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:45358/p_w/jf/collection1/ shard1
   [junit4]   2> 1339630 T4663 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1339631 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1339635 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1339638 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1339739 T4636 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> 1339739 T4645 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> 1339739 T4658 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> 1339786 T4663 oasc.ZkController.register We are http://127.0.0.1:45358/p_w/jf/collection1/ and leader is http://127.0.0.1:45358/p_w/jf/collection1/
   [junit4]   2> 1339786 T4663 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:45358/p_w/jf
   [junit4]   2> 1339787 T4663 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1339787 T4663 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 1339788 T4663 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1339790 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1339790 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1339791 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1339790 T4663 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1339792 T4637 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1339792 T4637 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:45358/p_w/jf",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:45358_p_w%2Fjf",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1339794 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1339863 T4614 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 1339864 T4614 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1339865 T4614 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51514
   [junit4]   2> 1339866 T4614 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1339867 T4614 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1339867 T4614 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-004
   [junit4]   2> 1339868 T4614 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-004/'
   [junit4]   2> 1339876 T4614 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-004/solr.xml
   [junit4]   2> 1339895 T4636 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> 1339895 T4645 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> 1339896 T4658 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> 1339909 T4614 oasc.CoreContainer.<init> New CoreContainer -1167837584
   [junit4]   2> 1339909 T4614 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-004/]
   [junit4]   2> 1339911 T4614 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1339911 T4614 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1339912 T4614 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1339912 T4614 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1339913 T4614 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1339913 T4614 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1339913 T4614 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1339914 T4614 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1339914 T4614 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1339915 T4614 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1339916 T4614 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1339916 T4614 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1339917 T4614 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50034/solr
   [junit4]   2> 1339917 T4614 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1339918 T4614 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1339920 T4674 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9111114f name:ZooKeeperConnection Watcher:127.0.0.1:50034 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1339920 T4614 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1339921 T4614 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1339922 T4676 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@969dc6e5 name:ZooKeeperConnection Watcher:127.0.0.1:50034/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1339922 T4614 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1339927 T4614 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1340929 T4614 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51514_p_w%2Fjf
   [junit4]   2> 1340930 T4614 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51514_p_w%2Fjf
   [junit4]   2> 1340936 T4636 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1340936 T4645 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1340936 T4658 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1340936 T4676 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1340942 T4677 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 1340942 T4677 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1340943 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1340943 T4677 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1340943 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1340944 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1340944 T4637 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1340945 T4637 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:51514/p_w/jf",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51514_p_w%2Fjf",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1340945 T4637 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 1340945 T4637 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1340947 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1341049 T4645 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> 1341049 T4658 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> 1341049 T4636 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> 1341049 T4676 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> 1341944 T4677 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1341944 T4677 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1341945 T4677 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1341945 T4677 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1341946 T4677 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1341946 T4677 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-004/collection1/'
   [junit4]   2> 1341947 T4677 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-004/collection1/lib/.svn/' to classloader
   [junit4]   2> 1341947 T4677 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-004/collection1/lib/classes/' to classloader
   [junit4]   2> 1341948 T4677 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-004/collection1/lib/README' to classloader
   [junit4]   2> 1341978 T4677 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
   [junit4]   2> 1342013 T4677 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1342014 T4677 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1342020 T4677 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1342342 T4677 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1342343 T4677 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1342343 T4677 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1342348 T4677 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1342350 T4677 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1342360 T4677 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1342363 T4677 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1342367 T4677 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1342367 T4677 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1342368 T4677 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1342368 T4677 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1342369 T4677 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1342369 T4677 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1342369 T4677 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1342370 T4677 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1342370 T4677 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-004/collection1/, dataDir=./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-001/jetty2/
   [junit4]   2> 1342370 T4677 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4c9adbd6
   [junit4]   2> 1342371 T4677 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-001/jetty2
   [junit4]   2> 1342371 T4677 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-001/jetty2/index/
   [junit4]   2> 1342371 T4677 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 1342372 T4677 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-001/jetty2/index
   [junit4]   2> 1342372 T4677 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=661686639, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 1342373 T4677 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1b28dd62 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@780ed388),segFN=segments_1,generation=1}
   [junit4]   2> 1342373 T4677 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1342377 T4677 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1342377 T4677 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1342377 T4677 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1342377 T4677 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1342378 T4677 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1342378 T4677 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1342378 T4677 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1342379 T4677 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1342379 T4677 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1342379 T4677 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1342380 T4677 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1342380 T4677 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1342380 T4677 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1342381 T4677 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1342381 T4677 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1342381 T4677 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1342383 T4677 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1342385 T4677 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1342385 T4677 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1342386 T4677 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=48, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=45.462890625, floorSegmentMB=2.0537109375, forceMergeDeletesPctAllowed=27.528139899562554, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.523838025257952
   [junit4]   2> 1342386 T4677 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1b28dd62 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@780ed388),segFN=segments_1,generation=1}
   [junit4]   2> 1342387 T4677 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1342387 T4677 oass.SolrIndexSearcher.<init> Opening Searcher@c08e55a9[collection1] main
   [junit4]   2> 1342387 T4677 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1342388 T4677 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1342388 T4677 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1342389 T4677 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1342389 T4677 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1342389 T4677 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1342390 T4677 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1342390 T4677 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1342390 T4677 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 1342391 T4677 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1342393 T4678 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c08e55a9[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1342394 T4677 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1342395 T4681 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51514/p_w/jf collection:collection1 shard:shard1
   [junit4]   2> 1342395 T4614 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 1342396 T4614 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1342397 T4681 oasc.ZkController.register We are http://127.0.0.1:51514/p_w/jf/collection1/ and leader is http://127.0.0.1:45358/p_w/jf/collection1/
   [junit4]   2> 1342397 T4681 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51514/p_w/jf
   [junit4]   2> 1342397 T4681 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 1342398 T4681 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C2040 name=collection1 org.apache.solr.core.SolrCore@b54cd13f url=http://127.0.0.1:51514/p_w/jf/collection1 node=127.0.0.1:51514_p_w%2Fjf C2040_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:51514/p_w/jf, core=collection1, node_name=127.0.0.1:51514_p_w%2Fjf}
   [junit4]   2> 1342398 T4682 C2040 P51514 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 1342398 T4681 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1342398 T4682 C2040 P51514 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 1342399 T4682 C2040 P51514 oasc.RecoveryStrategy.doRecovery Publishing state of core collection1 as recovering, leader is http://127.0.0.1:45358/p_w/jf/collection1/ and I am http://127.0.0.1:51514/p_w/jf/collection1/
   [junit4]   2> 1342399 T4682 C2040 P51514 oasc.ZkController.publish publishing core=collection1 state=recovering collection=collection1
   [junit4]   2> 1342399 T4682 C2040 P51514 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1342401 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1342401 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1342401 T4682 C2040 P51514 oasc.RecoveryStrategy.sendPrepRecoveryCmd Sending prep recovery command to http://127.0.0.1:45358/p_w/jf; WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1%3A51514_p_w%252Fjf&coreNodeName=core_node2&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true
   [junit4]   2> 1342401 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1342402 T4654 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
   [junit4]   2> 1342403 T4637 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1342404 T4654 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1342405 T4654 oasha.CoreAdminHandler.handleWaitForStateAction Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering
   [junit4]   2> 1342405 T4637 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:51514/p_w/jf",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51514_p_w%2Fjf",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 1342405 T4654 oasha.CoreAdminHandler.handleWaitForStateAction In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:51514_p_w%2Fjf, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"state":"down","base_url":"http://127.0.0.1:51514/p_w/jf","core":"collection1","node_name":"127.0.0.1:51514_p_w%2Fjf"}
   [junit4]   2> 1342407 T4636 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1342510 T4636 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> 1342510 T4645 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> 1342510 T4658 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> 1342511 T4676 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> 1342684 T4614 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 1342685 T4614 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1342687 T4614 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:45606
   [junit4]   2> 1342688 T4614 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1342688 T4614 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1342689 T4614 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-005
   [junit4]   2> 1342689 T4614 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-005/'
   [junit4]   2> 1342697 T4614 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-005/solr.xml
   [junit4]   2> 1342731 T4614 oasc.CoreContainer.<init> New CoreContainer -556067247
   [junit4]   2> 1342731 T4614 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001/tempDir-005/]
   [junit4]   2> 1342732 T4614 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1342733 T4614 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1342733 T4614 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1342734 T4614 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1342734 T4614 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1342735 T4614 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1342735 T4614 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1342736 T4614 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1342736 T4614 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1342737 T4614 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1342737 T4614 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1342738 T4614 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1342739 T4614 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50034/solr
   [junit4]   2> 1342739 T4614 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1342740 T4614 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1342741 T4694 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c7e07e2c name:ZooKeeperConnection Watcher:127.0.0.1:50034 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1342742 T4614 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1342744 T4614 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1342745 T4696 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e2f30e5a name:ZooKeeperConnection Watcher:127.0.0.1:50034/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1342745 T4614 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1342749 T4614 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1343406 T4654 oasha.CoreAdminHandler.handleWaitForStateAction In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:51514_p_w%2Fjf, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"state":"recovering","base_url":"http://127.0.0.1:51514/p_w/jf","core":"collection1","node_name":"127.0.0.1:51514_p_w%2Fjf"}
   [junit4]   2> 1343407 T4654 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
   [junit4]   2> 1343407 T4654 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={onlyIfLeaderActive=true&state=recovering&nodeName=127.0.0.1:51514_p_w%252Fjf&core=collection1&action=PREPRECOVERY&wt=javabin&version=2&coreNodeName=core_node2&onlyIfLeader=true&checkLive=true} status=0 QTime=1005 
   [junit4]   2> 1343751 T4614 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45606_p_w%2Fjf
   [junit4]   2> 1343752 T4614 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45606_p_w%2Fjf
   [junit4]   2> 1343754 T4645 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1343754 T4696 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1343754 T4636 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1343754 T4658 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1343755 T4676 oascc.ZkStateReader$3.process Upd

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

44)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:208)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:444)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:208)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:226)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:223)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:223)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.ensureExists(ZkCmdExecutor.java:100)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.ensureExists(ZkCmdExecutor.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.<init>(DistributedQueue.java:70)
   [junit4]   2> 	... 24 more
   [junit4]   2> 
   [junit4]   2> 1413669 T4717 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> 1413669 T4717 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1413669 T4717 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1413670 T4717 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=SyncSliceTest -Dtests.method=testDistribSearch -Dtests.seed=ADD85D71DFA185F3 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=sh_CS -Dtests.timezone=Europe/Zagreb -Dtests.file.encoding=UTF-8
   [junit4] ERROR   84.0s J0 | SyncSliceTest.testDistribSearch <<<
   [junit4]    > Throwable #1: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([ADD85D71DFA185F3:2C3ED369A8FEE5CF]:0)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:317)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:650)
   [junit4]    > 	at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
   [junit4]    > 	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1149)
   [junit4]    > 	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1118)
   [junit4]    > 	at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:236)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:853)
   [junit4]   2> 1413672 T4614 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-ADD85D71DFA185F3-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene46), sim=DefaultSimilarity, locale=sh_CS, timezone=Europe/Zagreb
   [junit4]   2> NOTE: Linux 3.8.0-41-generic x86/IBM Corporation 1.7.0 (32-bit)/cpus=8,threads=1,free=109759000,total=242417664
   [junit4]   2> NOTE: All tests run in this JVM: [TestCharFilters, URLClassifyProcessorTest, TestSuggestSpellingConverter, ShowFileRequestHandlerTest, TermsComponentTest, RegexBoostProcessorTest, BJQParserTest, LukeRequestHandlerTest, TestHighFrequencyDictionaryFactory, TestLFUCache, TestReplicationHandler, SolrInfoMBeanTest, ParsingFieldUpdateProcessorsTest, EchoParamsTest, QueryEqualityTest, SpatialFilterTest, BasicDistributedZkTest, TestFileDictionaryLookup, TestLRUCache, LoggingHandlerTest, SolrXmlInZkTest, TestSolrXmlPersistor, TestCopyFieldCollectionResource, TestCursorMarkWithoutUniqueKey, TestRealTimeGet, UnloadDistributedZkTest, TestElisionMultitermQuery, CoreMergeIndexesAdminHandlerTest, TestWriterPerf, TestDocumentBuilder, ReturnFieldsTest, SuggesterFSTTest, TestBlendedInfixSuggestions, TestMergePolicyConfig, QueryElevationComponentTest, ResourceLoaderTest, DistribCursorPagingTest, SliceStateTest, TestManagedStopFilterFactory, BadCopyFieldTest, ClusterStateUpdateTest, TestJoin, TestReloadAndDeleteDocs, PrimitiveFieldTypeTest, TestStressUserVersions, OverseerCollectionProcessorTest, TestLuceneMatchVersion, SchemaVersionSpecificBehaviorTest, TestTrie, TestSolrXMLSerializer, SOLR749Test, TestPHPSerializedResponseWriter, TestFieldSortValues, CSVRequestHandlerTest, PeerSyncTest, SSLMigrationTest, ShardRoutingTest, TermVectorComponentTest, CoreAdminRequestStatusTest, TestStressVersions, JsonLoaderTest, CircularListTest, TestPseudoReturnFields, TestSolrIndexConfig, AtomicUpdatesTest, ChangedSchemaMergeTest, BadComponentTest, TestSurroundQueryParser, OverseerTest, SolrIndexSplitterTest, LegacyHTMLStripCharFilterTest, DocumentBuilderTest, TestSchemaNameResource, TestUniqueKeyFieldResource, CopyFieldTest, DistributedTermsComponentTest, TestSolrQueryParserDefaultOperatorResource, AddSchemaFieldsUpdateProcessorFactoryTest, WordBreakSolrSpellCheckerTest, SearchHandlerTest, RecoveryZkTest, DistributedQueryElevationComponentTest, TestImplicitCoreProperties, TestGroupingSearch, ResponseLogComponentTest, ScriptEngineTest, EnumFieldTest, DistributedSuggestComponentTest, TestCoreContainer, SuggestComponentTest, TestLMJelinekMercerSimilarityFactory, TestBadConfig, DocValuesTest, TestDocBasedVersionConstraints, CacheHeaderTest, AnalysisAfterCoreReloadTest, CollectionsAPIDistributedZkTest, SyncSliceTest]
   [junit4] Completed on J0 in 84.07s, 1 test, 1 error <<< FAILURES!

[...truncated 841 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:460: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1297: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:921: There were test failures: 396 suites, 1640 tests, 1 error, 44 ignored (15 assumptions)

Total time: 94 minutes 33 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message