You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/04/23 20:00:40 UTC

[JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.7.0_60-ea-b14) - Build # 10144 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/10144/
Java: 64bit/jdk1.7.0_60-ea-b14 -XX:+UseCompressedOops -XX:+UseG1GC

1 tests failed.
REGRESSION:  org.apache.solr.cloud.LeaderElectionIntegrationTest.testSimpleSliceLeaderElection

Error Message:
No registered leader was found after waiting for 30000ms , collection: collection1 slice: shard1

Stack Trace:
org.apache.solr.common.SolrException: No registered leader was found after waiting for 30000ms , collection: collection1 slice: shard1
	at __randomizedtesting.SeedInfo.seed([876C18097D04DC88:D958D5473E7B406F]:0)
	at org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:611)
	at org.apache.solr.cloud.LeaderElectionIntegrationTest.getLeader(LeaderElectionIntegrationTest.java:255)
	at org.apache.solr.cloud.LeaderElectionIntegrationTest.testSimpleSliceLeaderElection(LeaderElectionIntegrationTest.java:179)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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 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:744)




Build Log:
[...truncated 11168 lines...]
   [junit4] Suite: org.apache.solr.cloud.LeaderElectionIntegrationTest
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/init-core-data-001
   [junit4]   2> 440688 T2360 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
   [junit4]   2> 440691 T2360 oas.SolrTestCaseJ4.setUp ###Starting testSimpleSliceLeaderElection
   [junit4]   2> 440692 T2360 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 440692 T2361 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 440792 T2360 oasc.ZkTestServer.run start zk server on port:47585
   [junit4]   2> 440793 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 446383 T2364 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 5588ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 446385 T2367 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b487fbf name:ZooKeeperConnection Watcher:127.0.0.1:47585 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 446385 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 446385 T2360 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 446389 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 446390 T2369 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f051196 name:ZooKeeperConnection Watcher:127.0.0.1:47585/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 446390 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 446390 T2360 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 446392 T2360 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 446394 T2360 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 446396 T2360 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 446398 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 446398 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 446401 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 446402 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 446405 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 446405 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 446407 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 446407 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 446409 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 446410 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 446414 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 446414 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 446418 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 446419 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 446422 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 446422 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 446424 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 446425 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 446427 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 446427 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 446429 T2360 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 446429 T2360 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 446431 T2360 oasc.LeaderElectionIntegrationTest.setUp ####SETUP_START testSimpleSliceLeaderElection
   [junit4]   2> 446432 T2360 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 446433 T2360 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr
   [junit4]   2> 446433 T2360 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/'
   [junit4]   2> 446449 T2360 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/solr.xml
   [junit4]   2> 446474 T2360 oasc.CoreContainer.<init> New CoreContainer 1081775436
   [junit4]   2> 446475 T2360 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/]
   [junit4]   2> 446475 T2360 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 446476 T2360 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: https
   [junit4]   2> 446476 T2360 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 446476 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 446476 T2360 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 446476 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 446477 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 446477 T2360 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 446477 T2360 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 446479 T2360 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 446479 T2360 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 446480 T2360 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 446480 T2360 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:47585/solr
   [junit4]   2> 446480 T2360 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 446481 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 446482 T2371 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@44df4f46 name:ZooKeeperConnection Watcher:127.0.0.1:47585 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 446482 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 446484 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 446486 T2373 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@783a7bf3 name:ZooKeeperConnection Watcher:127.0.0.1:47585/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 446486 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 446488 T2360 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 446491 T2360 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 446494 T2360 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 446497 T2360 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 446500 T2360 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 446503 T2360 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 446506 T2360 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:7000_solr
   [junit4]   2> 446506 T2360 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:7000_solr
   [junit4]   2> 446513 T2360 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 446515 T2360 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 446520 T2360 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:7000_solr
   [junit4]   2> 446521 T2360 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 446524 T2360 oasc.Overseer.start Overseer (id=91637357134610435-127.0.0.1:7000_solr-n_0000000000) starting
   [junit4]   2> 446529 T2360 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 446538 T2375 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 446538 T2360 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 446540 T2375 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:7000_solr
   [junit4]   2> 446541 T2360 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 446542 T2360 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 446545 T2374 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 446548 T2376 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 446548 T2376 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 446549 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 446549 T2376 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 446549 T2374 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 446551 T2374 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:7000/solr",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:7000_solr",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":null,
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 446554 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 446555 T2373 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> 447549 T2376 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 447549 T2376 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 447550 T2376 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 447550 T2376 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 447551 T2376 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 447551 T2376 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 447552 T2376 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
   [junit4]   2> 447552 T2376 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 447552 T2376 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 447642 T2376 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 447694 T2376 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 447695 T2376 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 447702 T2376 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 447907 T2376 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 447912 T2376 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 447914 T2376 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 447923 T2376 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 447926 T2376 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 447929 T2376 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 447930 T2376 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 447930 T2376 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 447931 T2376 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 447931 T2376 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 447931 T2376 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 447932 T2376 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 447932 T2376 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 447932 T2376 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-001/
   [junit4]   2> 447932 T2376 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7bad9a63
   [junit4]   2> 447933 T2376 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-001
   [junit4]   2> 447933 T2376 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-001/index/
   [junit4]   2> 447933 T2376 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-001/index' doesn't exist. Creating new index...
   [junit4]   2> 447933 T2376 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-001/index
   [junit4]   2> 447934 T2376 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=25, maxMergeAtOnceExplicit=24, maxMergedSegmentMB=77.4013671875, floorSegmentMB=0.607421875, forceMergeDeletesPctAllowed=27.99343068297479, segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2187977787211417
   [junit4]   2> 447934 T2376 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@7dfd5904 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@49df17f)),segFN=segments_1,generation=1}
   [junit4]   2> 447935 T2376 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 447935 T2376 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
   [junit4]   2> 447939 T2376 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 447939 T2376 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 447939 T2376 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 447940 T2376 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 447940 T2376 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 447940 T2376 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 447940 T2376 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 447941 T2376 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 447941 T2376 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 447941 T2376 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 447941 T2376 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 447941 T2376 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 447942 T2376 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 447942 T2376 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 447942 T2376 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 447943 T2376 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 447943 T2376 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
   [junit4]   2> 447943 T2376 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
   [junit4]   2> 447944 T2376 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 447944 T2376 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 447944 T2376 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 447945 T2376 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 447945 T2376 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 447945 T2376 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 447946 T2376 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 447946 T2376 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 447946 T2376 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 447947 T2376 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 447947 T2376 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 447947 T2376 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 447948 T2376 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 447948 T2376 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 447948 T2376 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 447949 T2376 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
   [junit4]   2> 447949 T2376 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
   [junit4]   2> 447951 T2376 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 447952 T2376 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 447954 T2376 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 447954 T2376 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 447955 T2376 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1242343159, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 447956 T2376 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@7dfd5904 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@49df17f)),segFN=segments_1,generation=1}
   [junit4]   2> 447956 T2376 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 447956 T2376 oass.SolrIndexSearcher.<init> Opening Searcher@4b8564fe[collection1] main
   [junit4]   2> 447956 T2376 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 447957 T2376 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 447957 T2376 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
   [junit4]   2> 447958 T2376 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
   [junit4]   2> 447958 T2376 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
   [junit4]   2> 447958 T2376 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 447958 T2376 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 447959 T2376 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 447963 T2376 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 447992 T2377 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4b8564fe[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 447997 T2376 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 447998 T2380 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:7000/solr collection:collection1 shard:shard1
   [junit4]   2> 447999 T2380 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 447999 T2360 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 447999 T2360 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr
   [junit4]   2> 447999 T2360 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/'
   [junit4]   2> 448005 T2380 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 448007 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 448007 T2380 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 448007 T2380 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 448008 T2374 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 448008 T2380 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:7000/solr/collection1/ shard1
   [junit4]   2> 448008 T2380 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 448012 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 448013 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 448015 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 448016 T2360 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/solr.xml
   [junit4]   2> 448042 T2360 oasc.CoreContainer.<init> New CoreContainer 915685457
   [junit4]   2> 448042 T2360 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/]
   [junit4]   2> 448043 T2360 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 448043 T2360 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: https
   [junit4]   2> 448043 T2360 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 448043 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 448044 T2360 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 448044 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 448044 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 448044 T2360 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 448044 T2360 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 448046 T2360 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 448047 T2360 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 448047 T2360 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 448047 T2360 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:47585/solr
   [junit4]   2> 448048 T2360 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 448048 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 448050 T2382 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@21d7854d name:ZooKeeperConnection Watcher:127.0.0.1:47585 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 448050 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 448052 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 448054 T2384 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4db55822 name:ZooKeeperConnection Watcher:127.0.0.1:47585/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 448054 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 448060 T2360 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 448117 T2384 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> 448117 T2373 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> 448164 T2380 oasc.ZkController.register We are http://127.0.0.1:7000/solr/collection1/ and leader is http://127.0.0.1:7000/solr/collection1/
   [junit4]   2> 448164 T2380 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:7000/solr
   [junit4]   2> 448164 T2380 oasc.ZkController.checkRecovery WARN Skipping recovery according to sys prop solrcloud.skip.autorecovery
   [junit4]   2> 448165 T2380 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 448165 T2380 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 448166 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 448166 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 448166 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 448166 T2380 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 448168 T2374 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 448169 T2374 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:7000/solr",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:7000_solr",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":null,
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 448171 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 448273 T2373 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> 448273 T2384 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> 449063 T2360 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:7001_solr
   [junit4]   2> 449064 T2360 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:7001_solr
   [junit4]   2> 449071 T2385 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 449071 T2385 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 449074 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 449074 T2385 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 449074 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 449074 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 449075 T2374 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 449077 T2374 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:7001/solr",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:7001_solr",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":null,
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 449078 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 449181 T2373 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> 449181 T2384 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> 450074 T2385 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 450074 T2385 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 450075 T2385 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 450075 T2385 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 450076 T2385 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 450076 T2385 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 450077 T2385 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
   [junit4]   2> 450077 T2385 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 450077 T2385 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 450117 T2385 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 450156 T2385 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 450157 T2385 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 450165 T2385 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 450386 T2385 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 450391 T2385 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 450392 T2385 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 450401 T2385 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 450404 T2385 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 450407 T2385 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 450408 T2385 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 450408 T2385 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 450408 T2385 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 450409 T2385 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 450409 T2385 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 450409 T2385 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 450409 T2385 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 450409 T2385 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-002/
   [junit4]   2> 450410 T2385 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7bad9a63
   [junit4]   2> 450410 T2385 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-002
   [junit4]   2> 450411 T2385 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-002/index/
   [junit4]   2> 450411 T2385 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-002/index' doesn't exist. Creating new index...
   [junit4]   2> 450411 T2385 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-002/index
   [junit4]   2> 450411 T2385 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=25, maxMergeAtOnceExplicit=24, maxMergedSegmentMB=77.4013671875, floorSegmentMB=0.607421875, forceMergeDeletesPctAllowed=27.99343068297479, segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2187977787211417
   [junit4]   2> 450412 T2385 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@2830106b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@56a085ff)),segFN=segments_1,generation=1}
   [junit4]   2> 450412 T2385 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 450413 T2385 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
   [junit4]   2> 450417 T2385 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 450417 T2385 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 450418 T2385 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 450418 T2385 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 450418 T2385 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 450418 T2385 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 450418 T2385 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 450419 T2385 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 450419 T2385 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 450419 T2385 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 450419 T2385 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 450420 T2385 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 450420 T2385 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 450420 T2385 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 450420 T2385 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 450421 T2385 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 450421 T2385 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
   [junit4]   2> 450422 T2385 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
   [junit4]   2> 450422 T2385 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 450423 T2385 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 450424 T2385 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 450424 T2385 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 450424 T2385 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 450424 T2385 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 450425 T2385 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 450425 T2385 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 450426 T2385 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 450427 T2385 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 450427 T2385 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 450428 T2385 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 450428 T2385 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 450429 T2385 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 450429 T2385 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 450429 T2385 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
   [junit4]   2> 450430 T2385 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
   [junit4]   2> 450432 T2385 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 450433 T2385 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 450435 T2385 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 450435 T2385 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 450436 T2385 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1242343159, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 450436 T2385 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@2830106b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@56a085ff)),segFN=segments_1,generation=1}
   [junit4]   2> 450436 T2385 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 450437 T2385 oass.SolrIndexSearcher.<init> Opening Searcher@50a589cf[collection1] main
   [junit4]   2> 450437 T2385 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 450438 T2385 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 450438 T2385 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
   [junit4]   2> 450438 T2385 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
   [junit4]   2> 450438 T2385 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
   [junit4]   2> 450439 T2385 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 450439 T2385 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 450439 T2385 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 450444 T2385 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 450470 T2386 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@50a589cf[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 450476 T2385 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 450478 T2389 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:7001/solr collection:collection1 shard:shard1
   [junit4]   2> 450479 T2360 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 450480 T2360 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr
   [junit4]   2> 450480 T2360 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/'
   [junit4]   2> 450483 T2389 oasc.ZkController.register We are http://127.0.0.1:7001/solr/collection1/ and leader is http://127.0.0.1:7000/solr/collection1/
   [junit4]   2> 450484 T2389 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:7001/solr
   [junit4]   2> 450484 T2389 oasc.ZkController.checkRecovery WARN Skipping recovery according to sys prop solrcloud.skip.autorecovery
   [junit4]   2> 450484 T2389 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 450484 T2389 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 450485 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 450485 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 450485 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 450486 T2389 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 450486 T2374 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 450489 T2374 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:7001/solr",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:7001_solr",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":null,
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 450492 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 450495 T2360 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/solr.xml
   [junit4]   2> 450519 T2360 oasc.CoreContainer.<init> New CoreContainer 1256347508
   [junit4]   2> 450519 T2360 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/]
   [junit4]   2> 450520 T2360 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 450520 T2360 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: https
   [junit4]   2> 450520 T2360 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 450520 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 450521 T2360 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 450521 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 450521 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 450521 T2360 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 450521 T2360 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 450524 T2360 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 450524 T2360 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 450524 T2360 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 450524 T2360 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:47585/solr
   [junit4]   2> 450524 T2360 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 450525 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 450526 T2391 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@88da95f name:ZooKeeperConnection Watcher:127.0.0.1:47585 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 450526 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 450529 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 450530 T2393 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@742832c0 name:ZooKeeperConnection Watcher:127.0.0.1:47585/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 450530 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 450535 T2360 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 450593 T2373 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> 450593 T2384 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> 450593 T2393 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> 451538 T2360 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:7002_solr
   [junit4]   2> 451539 T2360 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:7002_solr
   [junit4]   2> 451546 T2394 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 451546 T2394 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 451547 T2394 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 451547 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 451548 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 451548 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 451550 T2374 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 451551 T2374 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:7002/solr",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:7002_solr",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":null,
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 451556 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 451658 T2373 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> 451658 T2384 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> 451658 T2393 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> 452548 T2394 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 452548 T2394 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 452549 T2394 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 452549 T2394 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 452550 T2394 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 452550 T2394 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 452551 T2394 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
   [junit4]   2> 452551 T2394 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 452551 T2394 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 452598 T2394 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 452643 T2394 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 452644 T2394 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 452650 T2394 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 452877 T2394 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 452882 T2394 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 452884 T2394 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 452893 T2394 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 452897 T2394 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 452900 T2394 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 452901 T2394 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 452901 T2394 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 452901 T2394 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 452902 T2394 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 452902 T2394 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 452903 T2394 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 452903 T2394 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 452903 T2394 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-003/
   [junit4]   2> 452903 T2394 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7bad9a63
   [junit4]   2> 452904 T2394 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-003
   [junit4]   2> 452905 T2394 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-003/index/
   [junit4]   2> 452905 T2394 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-003/index' doesn't exist. Creating new index...
   [junit4]   2> 452905 T2394 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-003/index
   [junit4]   2> 452905 T2394 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=25, maxMergeAtOnceExplicit=24, maxMergedSegmentMB=77.4013671875, floorSegmentMB=0.607421875, forceMergeDeletesPctAllowed=27.99343068297479, segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2187977787211417
   [junit4]   2> 452906 T2394 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@106e99a8 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@207fa6f6)),segFN=segments_1,generation=1}
   [junit4]   2> 452906 T2394 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 452906 T2394 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
   [junit4]   2> 452911 T2394 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 452911 T2394 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 452911 T2394 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 452912 T2394 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 452912 T2394 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 452912 T2394 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 452912 T2394 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 452913 T2394 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 452913 T2394 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 452913 T2394 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 452913 T2394 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 452913 T2394 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 452914 T2394 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 452914 T2394 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 452914 T2394 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 452915 T2394 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 452915 T2394 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
   [junit4]   2> 452916 T2394 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
   [junit4]   2> 452916 T2394 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 452916 T2394 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 452917 T2394 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 452917 T2394 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 452917 T2394 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 452918 T2394 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 452918 T2394 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 452918 T2394 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 452919 T2394 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 452919 T2394 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 452920 T2394 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 452920 T2394 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 452920 T2394 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 452921 T2394 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 452921 T2394 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 452922 T2394 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
   [junit4]   2> 452922 T2394 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
   [junit4]   2> 452925 T2394 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 452926 T2394 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 452927 T2394 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 452928 T2394 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 452928 T2394 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1242343159, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 452929 T2394 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@106e99a8 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@207fa6f6)),segFN=segments_1,generation=1}
   [junit4]   2> 452929 T2394 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 452929 T2394 oass.SolrIndexSearcher.<init> Opening Searcher@70efc66[collection1] main
   [junit4]   2> 452930 T2394 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 452931 T2394 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 452931 T2394 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
   [junit4]   2> 452931 T2394 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
   [junit4]   2> 452931 T2394 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
   [junit4]   2> 452932 T2394 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 452932 T2394 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 452932 T2394 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 452936 T2394 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 452965 T2395 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@70efc66[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 452971 T2394 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 452971 T2398 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:7002/solr collection:collection1 shard:shard1
   [junit4]   2> 452972 T2360 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 452973 T2360 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr
   [junit4]   2> 452973 T2360 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/'
   [junit4]   2> 452978 T2398 oasc.ZkController.register We are http://127.0.0.1:7002/solr/collection1/ and leader is http://127.0.0.1:7000/solr/collection1/
   [junit4]   2> 452978 T2398 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:7002/solr
   [junit4]   2> 452979 T2398 oasc.ZkController.checkRecovery WARN Skipping recovery according to sys prop solrcloud.skip.autorecovery
   [junit4]   2> 452979 T2398 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 452979 T2398 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 452980 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 452980 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 452980 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 452981 T2398 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 452981 T2374 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 452983 T2374 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:7002/solr",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:7002_solr",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":null,
   [junit4]   2> 	  "core_node_name":"core_node3"}
   [junit4]   2> 452985 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 452990 T2360 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/solr.xml
   [junit4]   2> 453019 T2360 oasc.CoreContainer.<init> New CoreContainer 993374449
   [junit4]   2> 453019 T2360 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/]
   [junit4]   2> 453020 T2360 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 453020 T2360 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: https
   [junit4]   2> 453020 T2360 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 453021 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 453021 T2360 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 453021 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 453021 T2360 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 453022 T2360 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 453022 T2360 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 453024 T2360 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 453025 T2360 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 453025 T2360 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 453025 T2360 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:47585/solr
   [junit4]   2> 453025 T2360 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 453026 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 453028 T2400 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@746ca6d2 name:ZooKeeperConnection Watcher:127.0.0.1:47585 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 453028 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 453030 T2360 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 453031 T2402 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f7c684d name:ZooKeeperConnection Watcher:127.0.0.1:47585/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 453031 T2360 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 453036 T2360 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 453087 T2393 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> 453087 T2373 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> 453088 T2402 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> 453088 T2384 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> 454039 T2360 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:7003_solr
   [junit4]   2> 454040 T2360 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:7003_solr
   [junit4]   2> 454047 T2403 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 454047 T2403 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 454048 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 454048 T2403 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 454048 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 454048 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 454049 T2374 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 454050 T2374 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:7003/solr",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:7003_solr",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":null,
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 454052 T2373 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 454154 T2373 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> 454154 T2402 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> 454154 T2384 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> 454154 T2393 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> 455048 T2403 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 455049 T2403 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 455049 T2403 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 455049 T2403 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 455050 T2403 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 455051 T2403 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 455051 T2403 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
   [junit4]   2> 455051 T2403 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 455052 T2403 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 455089 T2403 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 455128 T2403 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 455129 T2403 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 455136 T2403 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 455341 T2403 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 455345 T2403 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 455347 T2403 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 455356 T2403 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 455359 T2403 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 455363 T2403 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 455364 T2403 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 455364 T2403 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 455364 T2403 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 455365 T2403 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 455365 T2403 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 455365 T2403 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 455365 T2403 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 455366 T2403 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-87

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

oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 522573 T2461 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 522586 T2479 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 522602 T2470 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 522985 T2450 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6515fd97 name:ZooKeeperConnection Watcher:127.0.0.1:46150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 522985 T2450 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: null state: SyncConnected type None
   [junit4]   2> 522986 T2360 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@4928cf0f
   [junit4]   2> 522987 T2451 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 522988 T2360 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
   [junit4]   2> 522988 T2360 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 522989 T2360 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 522989 T2360 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 522990 T2360 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 522990 T2360 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 522991 T2360 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-007 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-007;done=false>>]
   [junit4]   2> 522991 T2360 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-007
   [junit4]   2> 522991 T2450 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 522991 T2360 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-007/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-007/index;done=false>>]
   [junit4]   2> 522991 T2450 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> 522992 T2360 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001/tempDir-007/index
   [junit4]   2> 522992 T2451 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:7000_solr
   [junit4]   2> 522994 T2360 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:46150 46150
   [junit4]   2> 523064 T2438 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:46150 46150
   [junit4]   2> 523066 T2360 oas.SolrTestCaseJ4.tearDown ###Ending testLeaderElectionAfterClientTimeout
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 524493 T2450 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 524493 T2450 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 524494 T2506 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [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.getData(ZooKeeper.java:1155)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:329)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:293)
   [junit4]   2> 
   [junit4]   2> 525067 T2360 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.LeaderElectionIntegrationTest-876C18097D04DC88-001
   [junit4]   2> NOTE: test params are: codec=Lucene45, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=sr_ME, timezone=GB
   [junit4]   2> NOTE: Linux 3.8.0-38-generic amd64/Oracle Corporation 1.7.0_60-ea (64-bit)/cpus=8,threads=1,free=261878808,total=536870912
   [junit4]   2> NOTE: All tests run in this JVM: [TestComponentsName, DebugComponentTest, TestMiniSolrCloudCluster, SuggesterTSTTest, TestDynamicFieldCollectionResource, PluginInfoTest, FieldAnalysisRequestHandlerTest, TestReloadAndDeleteDocs, ResourceLoaderTest, SortByFunctionTest, SignatureUpdateProcessorFactoryTest, TestBinaryResponseWriter, TestPartialUpdateDeduplication, TestFieldTypeCollectionResource, TestFuzzyAnalyzedSuggestions, HdfsRecoveryZkTest, TestCSVResponseWriter, TestCursorMarkWithoutUniqueKey, TestSolrXMLSerializer, TestAnalyzedSuggestions, InfoHandlerTest, DateFieldTest, TestCollationField, CoreAdminRequestStatusTest, JSONWriterTest, DocumentAnalysisRequestHandlerTest, SolrPluginUtilsTest, DistributedExpandComponentTest, TestCloudManagedSchemaAddField, OverseerStatusTest, SolrCmdDistributorTest, TestSolrQueryParserResource, OverseerRolesTest, DeleteShardTest, RangeFacetTest, PathHierarchyTokenizerFactoryTest, XsltUpdateRequestHandlerTest, QueryResultKeyTest, AsyncMigrateRouteKeyTest, TestHighFrequencyDictionaryFactory, DOMUtilTest, AlternateDirectoryTest, TestIBSimilarityFactory, TestFastOutputStream, HdfsBasicDistributedZk2Test, TestCollationFieldDocValues, FunctionTest, TestDistributedGrouping, RequestHandlersTest, HdfsDirectoryTest, SolrTestCaseJ4Test, TestMultiCoreConfBootstrap, StandardRequestHandlerTest, TestSolrQueryParserDefaultOperatorResource, SpellCheckCollatorTest, NoCacheHeaderTest, DistributedSuggestComponentTest, LegacyHTMLStripCharFilterTest, SimplePostToolTest, ShardRoutingCustomTest, XmlUpdateRequestHandlerTest, HighlighterTest, TestManagedSchemaFieldResource, TestManagedResourceStorage, TestQuerySenderListener, TestDFRSimilarityFactory, DocValuesMissingTest, TestRecovery, UniqFieldsUpdateProcessorFactoryTest, TestExceedMaxTermLength, TestDistributedSearch, IndexSchemaRuntimeFieldTest, TestSolr4Spatial, TestHashPartitioner, MultiTermTest, TestCoreDiscovery, TestBlendedInfixSuggestions, TestCodecSupport, DistributedQueryComponentOptimizationTest, PrimUtilsTest, TestFastWriter, StressHdfsTest, TestLRUCache, DisMaxRequestHandlerTest, DirectSolrSpellCheckerTest, TestIndexingPerformance, MigrateRouteKeyTest, HdfsChaosMonkeySafeLeaderTest, LeaderElectionIntegrationTest]
   [junit4] Completed on J1 in 84.40s, 2 tests, 1 error <<< FAILURES!

[...truncated 690 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1296: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:920: There were test failures: 399 suites, 1669 tests, 1 error, 38 ignored (17 assumptions)

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