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/05/20 19:29:12 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.8.0_20-ea-b11) - Build
# 10228 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/10228/
Java: 32bit/jdk1.8.0_20-ea-b11 -client -XX:+UseConcMarkSweepGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.SyncSliceTest.testDistribSearch
Error Message:
No live SolrServers available to handle this request
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request
at __randomizedtesting.SeedInfo.seed([7C95EE41F34C65A6:FD7360598413059A]:0)
at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:317)
at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:636)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91)
at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1148)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1117)
at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:236)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11390 lines...]
[junit4] Suite: org.apache.solr.cloud.SyncSliceTest
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/init-core-data-001
[junit4] 2> 727622 T4504 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
[junit4] 2> 727622 T4504 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 727627 T4504 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 727628 T4504 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 727629 T4505 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 727729 T4504 oasc.ZkTestServer.run start zk server on port:43216
[junit4] 2> 727730 T4504 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 729407 T4508 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 1675ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
[junit4] 2> 729409 T4511 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a88c86 name:ZooKeeperConnection Watcher:127.0.0.1:43216 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 729409 T4504 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 729410 T4504 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 729419 T4504 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 729421 T4513 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f7eda4 name:ZooKeeperConnection Watcher:127.0.0.1:43216/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 729422 T4504 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 729422 T4504 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 729425 T4504 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 729428 T4504 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 729430 T4504 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 729433 T4504 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 729434 T4504 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 729439 T4504 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 729440 T4504 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 729444 T4504 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 729445 T4504 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 729448 T4504 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 729448 T4504 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 729450 T4504 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 729451 T4504 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 729453 T4504 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 729453 T4504 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 729455 T4504 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 729456 T4504 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 729458 T4504 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 729458 T4504 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 729461 T4504 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 729461 T4504 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 729464 T4504 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 729465 T4504 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 729468 T4504 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 729469 T4504 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 729762 T4504 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 729767 T4504 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:41607
[junit4] 2> 729768 T4504 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 729768 T4504 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 729769 T4504 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-002
[junit4] 2> 729769 T4504 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-002/'
[junit4] 2> 729785 T4504 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-002/solr.xml
[junit4] 2> 729808 T4504 oasc.CoreContainer.<init> New CoreContainer 17904261
[junit4] 2> 729809 T4504 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-002/]
[junit4] 2> 729810 T4504 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 729810 T4504 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 729810 T4504 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 729811 T4504 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 729811 T4504 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 729811 T4504 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 729812 T4504 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 729812 T4504 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 729812 T4504 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 729813 T4504 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 729813 T4504 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 729814 T4504 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 729814 T4504 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43216/solr
[junit4] 2> 729815 T4504 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 729816 T4504 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 729817 T4524 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7beed8 name:ZooKeeperConnection Watcher:127.0.0.1:43216 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 729818 T4504 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 729819 T4504 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 729821 T4526 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d91e04 name:ZooKeeperConnection Watcher:127.0.0.1:43216/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 729821 T4504 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 729823 T4504 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 729828 T4504 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 729831 T4504 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 729833 T4504 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 729836 T4504 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 729842 T4504 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 729844 T4504 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41607_
[junit4] 2> 729845 T4504 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:41607_
[junit4] 2> 729847 T4504 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 729849 T4504 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 729852 T4504 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:41607_
[junit4] 2> 729853 T4504 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 729854 T4504 oasc.Overseer.start Overseer (id=91790134823223299-127.0.0.1:41607_-n_0000000000) starting
[junit4] 2> 729857 T4504 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 729866 T4528 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 729867 T4504 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 729868 T4504 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 729870 T4504 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 729872 T4527 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 729874 T4529 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 729874 T4529 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 729875 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 729876 T4529 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 729876 T4527 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 729877 T4527 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:41607",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:41607_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 729877 T4527 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 729878 T4527 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 729880 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 729880 T4526 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> 730876 T4529 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 730876 T4529 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 730878 T4529 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 730878 T4529 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 730880 T4529 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 730880 T4529 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-002/collection1/'
[junit4] 2> 730881 T4529 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-002/collection1/lib/.svn/' to classloader
[junit4] 2> 730881 T4529 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-002/collection1/lib/classes/' to classloader
[junit4] 2> 730881 T4529 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-002/collection1/lib/README' to classloader
[junit4] 2> 730914 T4529 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
[junit4] 2> 730928 T4529 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 730929 T4529 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 730940 T4529 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 731094 T4529 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 731094 T4529 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 731095 T4529 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 731100 T4529 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 731102 T4529 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 731117 T4529 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 731120 T4529 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 731122 T4529 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 731123 T4529 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 731124 T4529 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 731124 T4529 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 731125 T4529 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 731125 T4529 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 731126 T4529 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 731126 T4529 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 731126 T4529 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-002/collection1/, dataDir=./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/control/data/
[junit4] 2> 731127 T4529 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1dde88e
[junit4] 2> 731127 T4529 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/control/data
[junit4] 2> 731128 T4529 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/control/data/index/
[junit4] 2> 731128 T4529 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 731128 T4529 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/control/data/index
[junit4] 2> 731129 T4529 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=10, maxMergedSegmentMB=69.2568359375, floorSegmentMB=0.783203125, forceMergeDeletesPctAllowed=28.46155467307377, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2890598750156156
[junit4] 2> 731129 T4529 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@16808fb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1408dcd),segFN=segments_1,generation=1}
[junit4] 2> 731130 T4529 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 731134 T4529 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 731134 T4529 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 731134 T4529 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 731134 T4529 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 731135 T4529 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 731135 T4529 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 731135 T4529 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 731136 T4529 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 731136 T4529 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 731137 T4529 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 731137 T4529 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 731137 T4529 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 731138 T4529 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 731138 T4529 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 731139 T4529 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 731139 T4529 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 731141 T4529 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 731143 T4529 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 731144 T4529 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 731145 T4529 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=35, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=67.64453125, floorSegmentMB=0.875, forceMergeDeletesPctAllowed=15.6488948517768, segmentsPerTier=49.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.867436134464664
[junit4] 2> 731145 T4529 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@16808fb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1408dcd),segFN=segments_1,generation=1}
[junit4] 2> 731145 T4529 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 731146 T4529 oass.SolrIndexSearcher.<init> Opening Searcher@202ee3[collection1] main
[junit4] 2> 731146 T4529 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 731147 T4529 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 731147 T4529 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 731148 T4529 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 731148 T4529 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 731148 T4529 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 731149 T4529 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 731149 T4529 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 731149 T4529 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 731149 T4529 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 731153 T4530 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@202ee3[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 731155 T4529 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 731156 T4533 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:41607 collection:control_collection shard:shard1
[junit4] 2> 731156 T4504 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 731157 T4504 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 731158 T4504 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 731159 T4533 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 731159 T4535 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f5d7c0 name:ZooKeeperConnection Watcher:127.0.0.1:43216/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 731160 T4504 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 731162 T4504 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 731164 T4504 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 731167 T4533 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 731170 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 731170 T4533 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 731170 T4533 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C2232 name=collection1 org.apache.solr.core.SolrCore@6bbdef url=http://127.0.0.1:41607/collection1 node=127.0.0.1:41607_ C2232_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:41607, core=collection1, node_name=127.0.0.1:41607_}
[junit4] 2> 731171 T4533 C2232 P41607 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:41607/collection1/
[junit4] 2> 731171 T4533 C2232 P41607 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 731171 T4533 C2232 P41607 oasc.SyncStrategy.syncToMe http://127.0.0.1:41607/collection1/ has no replicas
[junit4] 2> 731171 T4533 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:41607/collection1/ shard1
[junit4] 2> 731172 T4533 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 731172 T4527 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 731175 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 731177 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 731181 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 731284 T4526 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> 731287 T4535 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> 731329 T4533 oasc.ZkController.register We are http://127.0.0.1:41607/collection1/ and leader is http://127.0.0.1:41607/collection1/
[junit4] 2> 731330 T4533 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:41607
[junit4] 2> 731330 T4533 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 731330 T4533 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 731330 T4533 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 731332 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 731332 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 731332 T4533 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 731332 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 731334 T4527 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 731335 T4527 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:41607",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:41607_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 731337 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 731438 T4535 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> 731438 T4526 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> 731498 T4504 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 731499 T4504 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 731501 T4504 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49286
[junit4] 2> 731502 T4504 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 731502 T4504 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 731502 T4504 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-003
[junit4] 2> 731503 T4504 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-003/'
[junit4] 2> 731518 T4504 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-003/solr.xml
[junit4] 2> 731534 T4504 oasc.CoreContainer.<init> New CoreContainer 8094713
[junit4] 2> 731534 T4504 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-003/]
[junit4] 2> 731535 T4504 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 731535 T4504 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 731535 T4504 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 731536 T4504 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 731536 T4504 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 731536 T4504 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 731537 T4504 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 731537 T4504 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 731537 T4504 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 731538 T4504 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 731538 T4504 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 731539 T4504 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 731539 T4504 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43216/solr
[junit4] 2> 731539 T4504 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 731540 T4504 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 731541 T4546 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e36984 name:ZooKeeperConnection Watcher:127.0.0.1:43216 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 731542 T4504 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 731543 T4504 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 731544 T4548 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3232ff name:ZooKeeperConnection Watcher:127.0.0.1:43216/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 731545 T4504 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 731554 T4504 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 732557 T4504 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49286_
[junit4] 2> 732559 T4504 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49286_
[junit4] 2> 732562 T4526 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 732562 T4548 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 732562 T4535 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 732565 T4549 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 732566 T4549 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 732566 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 732567 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 732567 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 732567 T4549 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 732568 T4527 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 732568 T4527 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:49286",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49286_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 732569 T4527 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 732569 T4527 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 732571 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 732673 T4535 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> 732673 T4548 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> 732673 T4526 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> 733568 T4549 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 733568 T4549 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 733586 T4549 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 733587 T4549 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 733600 T4549 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 733600 T4549 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-003/collection1/'
[junit4] 2> 733601 T4549 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-003/collection1/lib/.svn/' to classloader
[junit4] 2> 733602 T4549 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-003/collection1/lib/classes/' to classloader
[junit4] 2> 733602 T4549 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-003/collection1/lib/README' to classloader
[junit4] 2> 733676 T4549 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
[junit4] 2> 733690 T4549 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 733691 T4549 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 733718 T4549 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 734053 T4549 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 734054 T4549 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 734055 T4549 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 734065 T4549 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 734068 T4549 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 734116 T4549 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 734125 T4549 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 734129 T4549 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 734134 T4549 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 734135 T4549 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 734135 T4549 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 734137 T4549 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 734138 T4549 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 734138 T4549 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 734138 T4549 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 734139 T4549 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-003/collection1/, dataDir=./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/jetty1/
[junit4] 2> 734139 T4549 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1dde88e
[junit4] 2> 734141 T4549 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/jetty1
[junit4] 2> 734141 T4549 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/jetty1/index/
[junit4] 2> 734141 T4549 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 734142 T4549 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/jetty1/index
[junit4] 2> 734143 T4549 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=10, maxMergedSegmentMB=69.2568359375, floorSegmentMB=0.783203125, forceMergeDeletesPctAllowed=28.46155467307377, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2890598750156156
[junit4] 2> 734150 T4549 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1237bf5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@10a22a2),segFN=segments_1,generation=1}
[junit4] 2> 734150 T4549 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 734177 T4549 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 734177 T4549 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 734178 T4549 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 734178 T4549 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 734178 T4549 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 734178 T4549 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 734179 T4549 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 734179 T4549 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 734179 T4549 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 734180 T4549 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 734181 T4549 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 734181 T4549 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 734182 T4549 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 734182 T4549 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 734183 T4549 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 734184 T4549 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 734186 T4549 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 734188 T4549 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 734188 T4549 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 734189 T4549 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=35, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=67.64453125, floorSegmentMB=0.875, forceMergeDeletesPctAllowed=15.6488948517768, segmentsPerTier=49.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.867436134464664
[junit4] 2> 734190 T4549 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1237bf5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@10a22a2),segFN=segments_1,generation=1}
[junit4] 2> 734190 T4549 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 734191 T4549 oass.SolrIndexSearcher.<init> Opening Searcher@1ed1467[collection1] main
[junit4] 2> 734191 T4549 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 734193 T4549 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 734193 T4549 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 734194 T4549 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 734194 T4549 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 734195 T4549 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 734196 T4549 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 734196 T4549 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 734197 T4549 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 734197 T4549 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 734208 T4549 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 734211 T4550 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1ed1467[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 734241 T4553 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49286 collection:collection1 shard:shard1
[junit4] 2> 734241 T4504 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 734242 T4504 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 734242 T4553 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 734252 T4553 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 734257 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 734258 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 734258 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 734258 T4553 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 734259 T4527 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 734260 T4553 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 734263 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 734264 T4526 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> 734265 T4535 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> ASYNC NEW_CORE C2233 name=collection1 org.apache.solr.core.SolrCore@7cec50 url=http://127.0.0.1:49286/collection1 node=127.0.0.1:49286_ C2233_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:49286, core=collection1, node_name=127.0.0.1:49286_}
[junit4] 2> 734263 T4553 C2233 P49286 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49286/collection1/
[junit4] 2> 734265 T4548 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> 734269 T4553 C2233 P49286 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 734269 T4553 C2233 P49286 oasc.SyncStrategy.syncToMe http://127.0.0.1:49286/collection1/ has no replicas
[junit4] 2> 734269 T4553 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49286/collection1/ shard1
[junit4] 2> 734270 T4553 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 734280 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 734281 T4527 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 734285 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 734387 T4535 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> 734387 T4526 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> 734387 T4548 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> 734433 T4553 oasc.ZkController.register We are http://127.0.0.1:49286/collection1/ and leader is http://127.0.0.1:49286/collection1/
[junit4] 2> 734437 T4553 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49286
[junit4] 2> 734437 T4553 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 734437 T4553 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 734438 T4553 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 734440 T4553 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 734443 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 734443 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 734444 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 734445 T4527 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 734446 T4527 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:49286",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49286_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 734449 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 734558 T4535 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> 734559 T4526 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> 734559 T4548 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> 734787 T4504 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 734789 T4504 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 734792 T4504 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:45870
[junit4] 2> 734793 T4504 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 734794 T4504 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 734795 T4504 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-004
[junit4] 2> 734795 T4504 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-004/'
[junit4] 2> 734817 T4504 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-004/solr.xml
[junit4] 2> 734833 T4504 oasc.CoreContainer.<init> New CoreContainer 20814601
[junit4] 2> 734834 T4504 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-004/]
[junit4] 2> 734835 T4504 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 734835 T4504 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 734836 T4504 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 734836 T4504 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 734836 T4504 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 734837 T4504 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 734837 T4504 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 734837 T4504 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 734838 T4504 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 734838 T4504 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 734839 T4504 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 734839 T4504 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 734839 T4504 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43216/solr
[junit4] 2> 734840 T4504 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 734841 T4504 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 734843 T4564 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a0ccf name:ZooKeeperConnection Watcher:127.0.0.1:43216 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 734844 T4504 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 734845 T4504 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 734848 T4566 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14981e7 name:ZooKeeperConnection Watcher:127.0.0.1:43216/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 734848 T4504 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 734860 T4504 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 735864 T4504 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45870_
[junit4] 2> 735865 T4504 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45870_
[junit4] 2> 735868 T4535 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 735868 T4548 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 735868 T4566 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 735868 T4526 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 735874 T4567 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 735874 T4567 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 735875 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 735875 T4567 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 735876 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 735876 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 735877 T4527 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 735878 T4527 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:45870",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:45870_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 735878 T4527 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 735879 T4527 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 735882 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 736012 T4526 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> 736012 T4535 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> 736012 T4548 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> 736012 T4566 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> 736876 T4567 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 736877 T4567 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 736882 T4567 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 736882 T4567 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 736883 T4567 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 736884 T4567 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-004/collection1/'
[junit4] 2> 736885 T4567 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-004/collection1/lib/.svn/' to classloader
[junit4] 2> 736885 T4567 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-004/collection1/lib/classes/' to classloader
[junit4] 2> 736886 T4567 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-004/collection1/lib/README' to classloader
[junit4] 2> 736941 T4567 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
[junit4] 2> 736955 T4567 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 736957 T4567 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 736965 T4567 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 737103 T4567 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 737104 T4567 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 737105 T4567 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 737110 T4567 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 737118 T4567 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 737130 T4567 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 737134 T4567 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 737137 T4567 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 737138 T4567 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 737138 T4567 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 737138 T4567 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 737139 T4567 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 737140 T4567 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 737140 T4567 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 737140 T4567 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 737140 T4567 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-004/collection1/, dataDir=./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/jetty2/
[junit4] 2> 737141 T4567 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1dde88e
[junit4] 2> 737142 T4567 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/jetty2
[junit4] 2> 737142 T4567 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/jetty2/index/
[junit4] 2> 737142 T4567 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 737142 T4567 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/jetty2/index
[junit4] 2> 737143 T4567 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=10, maxMergedSegmentMB=69.2568359375, floorSegmentMB=0.783203125, forceMergeDeletesPctAllowed=28.46155467307377, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2890598750156156
[junit4] 2> 737144 T4567 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@209ceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@17dc307),segFN=segments_1,generation=1}
[junit4] 2> 737144 T4567 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 737148 T4567 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 737149 T4567 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 737149 T4567 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 737149 T4567 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 737150 T4567 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 737150 T4567 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 737151 T4567 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 737151 T4567 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 737151 T4567 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 737152 T4567 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 737153 T4567 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 737153 T4567 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 737154 T4567 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 737155 T4567 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 737155 T4567 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 737156 T4567 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 737158 T4567 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 737160 T4567 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 737160 T4567 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 737161 T4567 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=35, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=67.64453125, floorSegmentMB=0.875, forceMergeDeletesPctAllowed=15.6488948517768, segmentsPerTier=49.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.867436134464664
[junit4] 2> 737162 T4567 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@209ceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@17dc307),segFN=segments_1,generation=1}
[junit4] 2> 737162 T4567 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 737163 T4567 oass.SolrIndexSearcher.<init> Opening Searcher@1e30ab3[collection1] main
[junit4] 2> 737163 T4567 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 737164 T4567 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 737164 T4567 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 737165 T4567 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 737165 T4567 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 737165 T4567 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 737166 T4567 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 737166 T4567 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 737166 T4567 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 737167 T4567 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 737172 T4568 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1e30ab3[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 737176 T4567 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 737177 T4571 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:45870 collection:collection1 shard:shard1
[junit4] 2> 737177 T4504 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 737178 T4504 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 737179 T4571 oasc.ZkController.register We are http://127.0.0.1:45870/collection1/ and leader is http://127.0.0.1:49286/collection1/
[junit4] 2> 737180 T4571 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:45870
[junit4] 2> 737180 T4571 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 737180 T4571 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C2234 name=collection1 org.apache.solr.core.SolrCore@16ff651 url=http://127.0.0.1:45870/collection1 node=127.0.0.1:45870_ C2234_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:45870, core=collection1, node_name=127.0.0.1:45870_}
[junit4] 2> 737180 T4572 C2234 P45870 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 737180 T4571 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 737181 T4572 C2234 P45870 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 737182 T4572 C2234 P45870 oasc.RecoveryStrategy.doRecovery Publishing state of core collection1 as recovering, leader is http://127.0.0.1:49286/collection1/ and I am http://127.0.0.1:45870/collection1/
[junit4] 2> 737182 T4572 C2234 P45870 oasc.ZkController.publish publishing core=collection1 state=recovering collection=collection1
[junit4] 2> 737182 T4572 C2234 P45870 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 737183 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 737183 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 737184 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 737184 T4572 C2234 P45870 oasc.RecoveryStrategy.sendPrepRecoveryCmd Sending prep recovery command to http://127.0.0.1:49286; WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1%3A45870_&coreNodeName=core_node2&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true
[junit4] 2> 737184 T4527 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 737185 T4527 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "base_url":"http://127.0.0.1:45870",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:45870_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 737186 T4544 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 737186 T4544 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 737187 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 737187 T4544 oasha.CoreAdminHandler.handleWaitForStateAction Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering
[junit4] 2> 737188 T4544 oasha.CoreAdminHandler.handleWaitForStateAction In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:45870_, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"state":"down","base_url":"http://127.0.0.1:45870","core":"collection1","node_name":"127.0.0.1:45870_"}
[junit4] 2> 737289 T4526 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> 737289 T4535 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> 737289 T4548 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> 737289 T4566 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> 737464 T4504 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 737465 T4504 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 737468 T4504 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:46472
[junit4] 2> 737469 T4504 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 737470 T4504 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 737470 T4504 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-005
[junit4] 2> 737471 T4504 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-005/'
[junit4] 2> 737497 T4504 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-005/solr.xml
[junit4] 2> 737511 T4504 oasc.CoreContainer.<init> New CoreContainer 30083473
[junit4] 2> 737512 T4504 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-005/]
[junit4] 2> 737512 T4504 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 737513 T4504 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 737513 T4504 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 737513 T4504 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 737514 T4504 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 737514 T4504 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 737515 T4504 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 737515 T4504 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 737515 T4504 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 737516 T4504 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 737517 T4504 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 737517 T4504 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 737518 T4504 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43216/solr
[junit4] 2> 737518 T4504 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 737519 T4504 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 737520 T4584 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@148572e name:ZooKeeperConnection Watcher:127.0.0.1:43216 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 737520 T4504 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 737522 T4504 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 737524 T4586 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c1715 name:ZooKeeperConnection Watcher:127.0.0.1:43216/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 737524 T4504 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 737529 T4504 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 738188 T4544 oasha.CoreAdminHandler.handleWaitForStateAction In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:45870_, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"state":"recovering","base_url":"http://127.0.0.1:45870","core":"collection1","node_name":"127.0.0.1:45870_"}
[junit4] 2> 738189 T4544 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 738189 T4544 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:45870_&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node2&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=1003
[junit4] 2> 738532 T4504 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46472_
[junit4] 2> 738534 T4504 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46472_
[junit4] 2> 738536 T4566 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 738536 T4535 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 738536 T4586 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 738536 T4548 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 738537 T4526 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 738540 T4587 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 738541 T4587 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 738541 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 738542 T4587 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 738542 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 738542 T4526 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 738543 T4527 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 738543 T4527 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:46472",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:46472_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 738544 T4527 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShard
[...truncated too long message...]
r-001/jetty4/index [CachedDir<<refCount=0;path=./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/jetty4/index;done=false>>]
[junit4] 2> 786390 T4606 oasc.CachingDirectoryFactory.close Closing directory: ./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/jetty4/index
[junit4] 2> 786390 T4606 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/jetty4 [CachedDir<<refCount=0;path=./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/jetty4;done=false>>]
[junit4] 2> 786391 T4606 oasc.CachingDirectoryFactory.close Closing directory: ./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001/tempDir-001/jetty4
[junit4] 2> 786391 T4606 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue/qn-
[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.create(ZooKeeper.java:783)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:243)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:240)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:240)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.createData(DistributedQueue.java:311)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.offer(DistributedQueue.java:295)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:190)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:444)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:208)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:444)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:208)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:444)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:208)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 786394 T4606 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> 786395 T4606 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 786395 T4606 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 786396 T4606 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.SyncSliceTest-7C95EE41F34C65A6-001
[junit4] 2> NOTE: test params are: codec=Lucene42, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=zh, timezone=Etc/GMT-0
[junit4] 2> NOTE: Linux 3.8.0-39-generic i386/Oracle Corporation 1.8.0_20-ea (32-bit)/cpus=8,threads=1,free=112423008,total=218525696
[junit4] 2> NOTE: All tests run in this JVM: [TestDistribDocBasedVersion, TestExpandComponent, TermsComponentTest, ShowFileRequestHandlerTest, TestValueSourceCache, URLClassifyProcessorTest, TestQueryUtils, TestRemoteStreaming, DistributedQueryElevationComponentTest, TestSchemaSimilarityResource, TestPseudoReturnFields, TestFieldTypeCollectionResource, TestLuceneMatchVersion, SampleTest, TestAnalyzeInfixSuggestions, UpdateParamsTest, TestDocumentBuilder, CacheHeaderTest, TestCopyFieldCollectionResource, MigrateRouteKeyTest, ShardSplitTest, JsonLoaderTest, ResourceLoaderTest, TestExtendedDismaxParser, HdfsCollectionsAPIDistributedZkTest, ExternalFileFieldSortTest, TestCoreContainer, TestManagedSynonymFilterFactory, SliceStateUpdateTest, HdfsLockFactoryTest, TestSolrQueryParser, TestHighlightDedupGrouping, LoggingHandlerTest, SuggesterFSTTest, RemoteQueryErrorTest, AliasIntegrationTest, TestDocSet, TestRealTimeGet, TestWriterPerf, TestCustomSort, QueryParsingTest, TestJmxMonitoredMap, TestMaxScoreQueryParser, TestLMJelinekMercerSimilarityFactory, ClusterStateTest, TestReplicationHandler, SpellPossibilityIteratorTest, DistribCursorPagingTest, PeerSyncTest, TestDistributedMissingSort, FieldMutatingUpdateProcessorTest, ClusterStateUpdateTest, TestConfigSets, TestLFUCache, SuggesterTest, SoftAutoCommitTest, TermVectorComponentTest, TestSchemaNameResource, TestSurroundQueryParser, RegexBoostProcessorTest, CoreMergeIndexesAdminHandlerTest, OverseerTest, SchemaVersionSpecificBehaviorTest, TestLRUCache, UpdateRequestProcessorFactoryTest, ShardRoutingTest, DocumentBuilderTest, TestSolrDeletionPolicy1, ZkCLITest, FastVectorHighlighterTest, MoreLikeThisHandlerTest, TestFieldSortValues, DocValuesTest, BadCopyFieldTest, TestHighFrequencyDictionaryFactory, TestTrie, TestReversedWildcardFilterFactory, StatelessScriptUpdateProcessorFactoryTest, QueryElevationComponentTest, UUIDFieldTest, TestInitQParser, DOMUtilTest, HttpPartitionTest, OverseerRolesTest, CachingDirectoryFactoryTest, FileBasedSpellCheckerTest, TestSolrXml, TestStandardQParsers, TestNRTOpen, TestCollationFieldDocValues, CopyFieldTest, TestManagedSchema, SolrIndexSplitterTest, TestFileDictionaryLookup, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, SyncSliceTest]
[junit4] Completed on J0 in 58.99s, 1 test, 1 error <<< FAILURES!
[...truncated 611 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1297: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:921: There were test failures: 394 suites, 1638 tests, 1 error, 37 ignored (16 assumptions)
Total time: 59 minutes 32 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0_20-ea-b11 -client -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure