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/02/09 15:50:03 UTC
[JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.8.0-fcs-b128) - Build
# 9417 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9417/
Java: 64bit/jdk1.8.0-fcs-b128 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
Error Message:
createcollection the collection time out:60s
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: createcollection the collection time out:60s
at __randomizedtesting.SeedInfo.seed([EC497D9642030185:6DAFF38E355C61B9]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:495)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testNodesUsedByCreate(CollectionsAPIDistributedZkTest.java:589)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:201)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:867)
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:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:744)
Build Log:
[...truncated 10460 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> 552677 T3098 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 552682 T3098 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1391956615466
[junit4] 2> 552683 T3098 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 552684 T3099 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 552784 T3098 oasc.ZkTestServer.run start zk server on port:60308
[junit4] 2> 552784 T3098 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 552943 T3105 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@43cfcd11 name:ZooKeeperConnection Watcher:127.0.0.1:60308 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 552944 T3098 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 552944 T3098 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 552948 T3098 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 552951 T3107 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@725a2fb4 name:ZooKeeperConnection Watcher:127.0.0.1:60308/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 552951 T3098 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 552951 T3098 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 552954 T3098 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 552956 T3098 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 552957 T3098 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 552959 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 552959 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 552962 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 552963 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 552966 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 552967 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 552982 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 552982 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 552985 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 552985 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 552988 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 552988 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 552991 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 552991 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 552993 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 552994 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 552995 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 552996 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 552998 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 552998 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 553002 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 553003 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> Using new style solr.xml
[junit4] 2> 553008 T3098 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 553009 T3109 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@309f1bd4 name:ZooKeeperConnection Watcher:127.0.0.1:60308 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 553010 T3098 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 553010 T3098 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 553013 T3098 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 553014 T3111 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2d2f83d5 name:ZooKeeperConnection Watcher:127.0.0.1:60308/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 553014 T3098 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 553015 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf2/solrconfig.xml
[junit4] 2> 553015 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.xml
[junit4] 2> 553019 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf2/schema.xml
[junit4] 2> 553019 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf2/schema.xml
[junit4] 2> 553022 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf2/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 553022 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 553024 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf2/stopwords.txt
[junit4] 2> 553025 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf2/stopwords.txt
[junit4] 2> 553028 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf2/protwords.txt
[junit4] 2> 553028 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf2/protwords.txt
[junit4] 2> 553031 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf2/currency.xml
[junit4] 2> 553032 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf2/currency.xml
[junit4] 2> 553034 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf2/open-exchange-rates.json
[junit4] 2> 553034 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf2/open-exchange-rates.json
[junit4] 2> 553036 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf2/mapping-ISOLatin1Accent.txt
[junit4] 2> 553036 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf2/mapping-ISOLatin1Accent.txt
[junit4] 2> 553039 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf2/old_synonyms.txt
[junit4] 2> 553039 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf2/old_synonyms.txt
[junit4] 2> 553041 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf2/synonyms.txt
[junit4] 2> 553042 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf2/synonyms.txt
[junit4] 2> 553044 T3098 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/elevate.xml to /configs/conf2/elevate.xml
[junit4] 2> 553044 T3098 oascc.SolrZkClient.makePath makePath: /configs/conf2/elevate.xml
[junit4] 2> 553151 T3098 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 553155 T3098 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57325
[junit4] 2> 553157 T3098 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 553157 T3098 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 553158 T3098 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391956615834
[junit4] 2> 553158 T3098 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391956615834/'
[junit4] 2> 553167 T3098 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391956615834/solr.xml
[junit4] 2> 553181 T3098 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 553181 T3098 oasc.CoreContainer.<init> New CoreContainer 1697548116
[junit4] 2> 553181 T3098 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391956615834/]
[junit4] 2> 553182 T3098 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 553182 T3098 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 553182 T3098 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 553182 T3098 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 553183 T3098 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 553183 T3098 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 553183 T3098 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 553183 T3098 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 553184 T3098 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 553185 T3098 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 553185 T3098 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 553186 T3098 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 553186 T3098 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60308/solr
[junit4] 2> 553186 T3098 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 553187 T3098 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 553188 T3122 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6d8b211e name:ZooKeeperConnection Watcher:127.0.0.1:60308 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 553189 T3098 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 553190 T3098 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 553191 T3124 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50eeaeac name:ZooKeeperConnection Watcher:127.0.0.1:60308/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 553191 T3098 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 553193 T3098 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 553195 T3098 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 553197 T3098 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 553198 T3098 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57325_
[junit4] 2> 553199 T3098 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57325_
[junit4] 2> 553201 T3098 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 553203 T3098 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 553205 T3098 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57325_
[junit4] 2> 553206 T3098 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 553208 T3098 oasc.Overseer.start Overseer (id=91223268751310853-127.0.0.1:57325_-n_0000000000) starting
[junit4] 2> 553212 T3098 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 553215 T3126 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 553215 T3098 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 553216 T3126 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 553217 T3098 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 553219 T3098 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 553220 T3125 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 553221 T3098 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391956615834
[junit4] 2> 553223 T3098 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391956615834/conf/
[junit4] 2> 553274 T3098 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 553275 T3098 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 553275 T3098 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 553276 T3098 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 553277 T3129 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18bfb453 name:ZooKeeperConnection Watcher:127.0.0.1:60308/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 553277 T3098 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 553278 T3098 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 553280 T3098 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 553376 T3098 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 553377 T3098 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 553379 T3098 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52258
[junit4] 2> 553379 T3098 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 553380 T3098 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 553380 T3098 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391956616063
[junit4] 2> 553380 T3098 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391956616063/'
[junit4] 2> 553394 T3098 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391956616063/solr.xml
[junit4] 2> 553403 T3098 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 553404 T3098 oasc.CoreContainer.<init> New CoreContainer 347306704
[junit4] 2> 553404 T3098 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391956616063/]
[junit4] 2> 553405 T3098 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 553405 T3098 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 553405 T3098 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 553406 T3098 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 553406 T3098 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 553406 T3098 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 553407 T3098 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 553407 T3098 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 553407 T3098 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 553410 T3098 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 553410 T3098 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 553411 T3098 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 553411 T3098 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60308/solr
[junit4] 2> 553411 T3098 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 553412 T3098 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 553414 T3140 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51bdf865 name:ZooKeeperConnection Watcher:127.0.0.1:60308 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 553414 T3098 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 553416 T3098 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 553417 T3142 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@294c7050 name:ZooKeeperConnection Watcher:127.0.0.1:60308/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 553417 T3098 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 553420 T3098 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 554422 T3098 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52258_
[junit4] 2> 554423 T3098 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52258_
[junit4] 2> 554426 T3142 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 554426 T3124 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 554426 T3129 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 554430 T3098 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391956616063
[junit4] 2> 554431 T3098 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391956616063/conf/
[junit4] 2> 554494 T3098 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 554494 T3098 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 554495 T3098 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 554593 T3098 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 554594 T3098 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 554596 T3098 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49763
[junit4] 2> 554596 T3098 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 554596 T3098 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 554597 T3098 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391956617278
[junit4] 2> 554597 T3098 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391956617278/'
[junit4] 2> 554611 T3098 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391956617278/solr.xml
[junit4] 2> 554620 T3098 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 554621 T3098 oasc.CoreContainer.<init> New CoreContainer 1724642602
[junit4] 2> 554621 T3098 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391956617278/]
[junit4] 2> 554622 T3098 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 554622 T3098 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 554622 T3098 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 554623 T3098 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 554623 T3098 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 554623 T3098 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 554624 T3098 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 554624 T3098 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 554624 T3098 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 554627 T3098 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 554627 T3098 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 554627 T3098 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 554628 T3098 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60308/solr
[junit4] 2> 554628 T3098 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 554629 T3098 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 554630 T3154 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@49a18dae name:ZooKeeperConnection Watcher:127.0.0.1:60308 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 554631 T3098 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 554633 T3098 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 554634 T3156 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9af04fe name:ZooKeeperConnection Watcher:127.0.0.1:60308/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 554634 T3098 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 554639 T3098 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 555641 T3098 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49763_
[junit4] 2> 555643 T3098 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49763_
[junit4] 2> 555645 T3156 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 555646 T3124 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 555645 T3142 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 555646 T3129 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 555649 T3098 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391956617278
[junit4] 2> 555650 T3098 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391956617278/conf/
[junit4] 2> 555685 T3098 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 555686 T3098 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 555686 T3098 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 555750 T3098 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 555750 T3098 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 555752 T3098 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47250
[junit4] 2> 555753 T3098 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 555753 T3098 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 555753 T3098 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391956618469
[junit4] 2> 555753 T3098 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391956618469/'
[junit4] 2> 555762 T3098 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391956618469/solr.xml
[junit4] 2> 555775 T3098 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 555776 T3098 oasc.CoreContainer.<init> New CoreContainer 1691962750
[junit4] 2> 555776 T3098 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391956618469/]
[junit4] 2> 555776 T3098 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 555777 T3098 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 555777 T3098 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 555777 T3098 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 555777 T3098 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 555777 T3098 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 555778 T3098 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 555778 T3098 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 555778 T3098 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 555780 T3098 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 555780 T3098 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 555780 T3098 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 555780 T3098 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60308/solr
[junit4] 2> 555781 T3098 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 555781 T3098 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 555783 T3168 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ee15cea name:ZooKeeperConnection Watcher:127.0.0.1:60308 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 555783 T3098 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 555784 T3098 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 555785 T3170 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@255afa76 name:ZooKeeperConnection Watcher:127.0.0.1:60308/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 555785 T3098 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 555790 T3098 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 556792 T3098 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47250_
[junit4] 2> 556793 T3098 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47250_
[junit4] 2> 556796 T3124 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 556796 T3129 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 556796 T3156 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 556796 T3142 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 556796 T3170 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 556799 T3098 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391956618469
[junit4] 2> 556800 T3098 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391956618469/conf/
[junit4] 2> 556853 T3098 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 556854 T3098 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 556854 T3098 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 556917 T3098 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 4
[junit4] 2> 556917 T3098 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 556919 T3098 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:37226
[junit4] 2> 556919 T3098 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 556920 T3098 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 556920 T3098 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391956619637
[junit4] 2> 556920 T3098 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391956619637/'
[junit4] 2> 556929 T3098 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391956619637/solr.xml
[junit4] 2> 556943 T3098 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 556943 T3098 oasc.CoreContainer.<init> New CoreContainer 2005852241
[junit4] 2> 556943 T3098 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391956619637/]
[junit4] 2> 556944 T3098 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 556944 T3098 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 556944 T3098 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 556944 T3098 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 556945 T3098 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 556945 T3098 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 556945 T3098 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 556945 T3098 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 556946 T3098 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 556947 T3098 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 556947 T3098 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 556948 T3098 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 556948 T3098 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60308/solr
[junit4] 2> 556948 T3098 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 556949 T3098 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 556950 T3182 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b97f717 name:ZooKeeperConnection Watcher:127.0.0.1:60308 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 556950 T3098 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 556951 T3098 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 556953 T3184 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f89a60b name:ZooKeeperConnection Watcher:127.0.0.1:60308/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 556953 T3098 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 556955 T3098 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 557957 T3098 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37226_
[junit4] 2> 557958 T3098 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37226_
[junit4] 2> 557961 T3142 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 557961 T3156 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 557961 T3170 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 557961 T3129 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 557961 T3184 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 557961 T3124 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 557963 T3098 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391956619637
[junit4] 2> 557964 T3098 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391956619637/conf/
[junit4] 2> 557987 T3098 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 557987 T3098 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 557987 T3098 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 557996 T3137 oasha.CollectionsHandler.handleCreateAction Creating Collection : replicationFactor=2&collection.configName=conf1&router.field=myOwnField&name=solrj_collection&router.name=compositeId&action=CREATE&numShards=2&wt=javabin&version=2
[junit4] 2> 557998 T3124 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4] 2> 557998 T3126 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
[junit4] 2> "operation":"createcollection",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"solrj_collection",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "router.field":"myOwnField",
[junit4] 2> "router.name":"compositeId"}
[junit4] 2> 557998 T3126 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
[junit4] 2> "operation":"createcollection",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"solrj_collection",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "router.field":"myOwnField",
[junit4] 2> "router.name":"compositeId"}
[junit4] 2> 557999 T3126 oasc.OverseerCollectionProcessor.createConfNode creating collections conf node /collections/solrj_collection
[junit4] 2> 557999 T3126 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
[junit4] 2> 558001 T3124 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 558002 T3125 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 558003 T3125 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
[junit4] 2> 558003 T3125 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
[junit4] 2> 558004 T3124 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 558005 T3142 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 558005 T3170 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 558005 T3156 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 558005 T3184 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 558005 T3124 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 558005 T3129 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 558102 T3126 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
[junit4] 2> 558102 T3126 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:47250_
[junit4] 2> 558103 T3126 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:37226_
[junit4] 2> 558103 T3126 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:57325_
[junit4] 2> 558105 T3126 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:49763_
[junit4] 2> 558108 T3179 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down
[junit4] 2> 558108 T3119 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down
[junit4] 2> 558108 T3165 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down
[junit4] 2> 558109 T3124 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 558110 T3179 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 558109 T3150 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down
[junit4] 2> 558110 T3119 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 558112 T3165 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 558112 T3150 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 558112 T3124 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 558113 T3125 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 558114 T3125 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:37226",
[junit4] 2> "core":"solrj_collection_shard1_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37226_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 558118 T3125 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:57325",
[junit4] 2> "core":"solrj_collection_shard2_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:57325_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 558121 T3124 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 558122 T3125 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:47250",
[junit4] 2> "core":"solrj_collection_shard1_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:47250_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 558125 T3124 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 558127 T3125 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:49763",
[junit4] 2> "core":"solrj_collection_shard2_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49763_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 558131 T3124 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 558234 T3142 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 558234 T3129 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 558234 T3156 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 558234 T3170 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 558234 T3184 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 558234 T3124 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 559111 T3179 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
[junit4] 2> 559111 T3119 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
[junit4] 2> 559112 T3179 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391956619637/solrj_collection_shard1_replica2
[junit4] 2> 559112 T3179 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 559113 T3150 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
[junit4] 2> 559112 T3119 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391956615834/solrj_collection_shard2_replica1
[junit4] 2> 559114 T3119 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 559114 T3150 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391956617278/solrj_collection_shard2_replica2
[junit4] 2> 559115 T3150 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 559115 T3119 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 559116 T3119 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 559116 T3150 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 559116 T3150 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 559112 T3165 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
[junit4] 2> 559117 T3119 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 559113 T3179 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 559118 T3165 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391956618469/solrj_collection_shard1_replica1
[junit4] 2> 559118 T3165 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 559118 T3119 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391956615834/solrj_collection_shard2_replica1/'
[junit4] 2> 559119 T3165 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 559120 T3165 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 559119 T3150 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 559121 T3150 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391956617278/solrj_collection_shard2_replica2/'
[junit4] 2> 559118 T3179 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 559121 T3165 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 559122 T3165 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391956618469/solrj_collection_shard1_replica1/'
[junit4] 2> 559123 T3179 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 559123 T3179 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391956619637/solrj_collection_shard1_replica2/'
[junit4] 2> 559154 T3119 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 559167 T3150 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 559168 T3179 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 559186 T3165 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 559187 T3119 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 559189 T3119 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 559198 T3150 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 559200 T3179 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 559200 T3150 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 559201 T3179 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 559205 T3119 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
[junit4] 2> 559209 T3150 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
[junit4] 2> 559209 T3165 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 559211 T3179 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
[junit4] 2> 559211 T3165 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 559224 T3165 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
[junit4] 2> 559411 T3119 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 559414 T3150 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 559424 T3119 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 559425 T3150 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 559426 T3150 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 559427 T3119 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 559436 T3150 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 559437 T3119 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 559439 T3150 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 559440 T3119 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 559442 T3150 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 559443 T3119 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 559443 T3150 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 559443 T3150 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 559448 T3150 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 559448 T3119 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 559448 T3119 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 559448 T3119 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 559449 T3119 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 559450 T3119 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 559450 T3150 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 559450 T3150 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 559450 T3119 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 559451 T3150 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 559450 T3165 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 559451 T3150 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391956617278/solrj_collection_shard2_replica2/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391956617278/solrj_collection_shard2_replica2/data/
[junit4] 2> 559451 T3119 oasc.SolrCore.<init> [solrj_collection_shard2_replica1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391956615834/solrj_collection_shard2_replica1/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391956615834/solrj_collection_shard2_replica1/data/
[junit4] 2> 559452 T3150 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@11f932d4
[junit4] 2> 559452 T3119 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@11f932d4
[junit4] 2> 559453 T3150 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391956617278/solrj_collection_shard2_replica2/data
[junit4] 2> 559453 T3119 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391956615834/solrj_collection_shard2_replica1/data
[junit4] 2> 559453 T3119 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391956615834/solrj_collection_shard2_replica1/data/index/
[junit4] 2> 559453 T3150 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391956617278/solrj_collection_shard2_replica2/data/index/
[junit4] 2> 559453 T3119 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica1] Solr index directory '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391956615834/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4] 2> 559454 T3150 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391956617278/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4] 2> 559454 T3119 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391956615834/solrj_collection_shard2_replica1/data/index
[junit4] 2> 559454 T3150 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391956617278/solrj_collection_shard2_replica2/data/index
[junit4] 2> 559455 T3119 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=228034222, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 559456 T3150 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=228034222, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 559456 T3119 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@50b10685 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@727a9d3f),segFN=segments_1,generation=1}
[junit4] 2> 559456 T3119 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 559456 T3150 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@78c58ac1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1407d061),segFN=segments_1,generation=1}
[junit4] 2> 559457 T3150 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 559459 T3119 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 559460 T3150 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 559460 T3150 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 559460 T3150 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 559461 T3150 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 559461 T3179 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 559456 T3165 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 559461 T3150 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 559460 T3119 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 559462 T3119 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 559462 T3119 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 559463 T3119 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 559463 T3119 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 559463 T3165 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 559463 T3150 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 559464 T3150 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 559464 T3150 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 559464 T3150 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 559465 T3150 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 559463 T3119 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 559465 T3150 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 559466 T3150 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 559464 T3179 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 559466 T3150 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 559466 T3119 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 559468 T3179 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 559467 T3150 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 559469 T3150 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 559469 T3150 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 559470 T3150 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 559472 T3150 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 559468 T3119 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 559473 T3165 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 559473 T3119 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 559474 T3119 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 559474 T3119 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 559474 T3119 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 559475 T3119 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 559475 T3119 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 559476 T3119 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 559476 T3165 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 559476 T3119 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 559476 T3179 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 559478 T3119 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 559478 T3165 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 559478 T3179 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 559479 T3165 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 559480 T3165 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 559479 T3150 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 559480 T3165 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 559480 T3119 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 559480 T3150 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 559481 T3119 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 559481 T3179 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 559481 T3119 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=22, maxMergedSegmentMB=49.6328125, floorSegmentMB=1.1826171875, forceMergeDeletesPctAllowed=12.351639609961927, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 559481 T3165 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 559482 T3179 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 559482 T3179 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 559482 T3179 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 559481 T3150 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=22, maxMergedSegmentMB=49.6328125, floorSegmentMB=1.1826171875, forceMergeDeletesPctAllowed=12.351639609961927, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 559482 T3165 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 559482 T3119 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@50b10685 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@727a9d3f),segFN=segments_1,generation=1}
[junit4] 2> 559483 T3119 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 559483 T3119 oass.SolrIndexSearcher.<init> Opening Searcher@3b32509b[solrj_collection_shard2_replica1] main
[junit4] 2> 559483 T3165 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 559483 T3179 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 559484 T3179 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 559483 T3150 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@78c58ac1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1407d061),segFN=segments_1,generation=1}
[junit4] 2> 559485 T3150 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 559485 T3179 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 559484 T3165 oasc.SolrCore.<init> [solrj_collection_shard1_replica1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391956618469/solrj_collection_shard1_replica1/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391956618469/solrj_collection_shard1_replica1/data/
[junit4] 2> 559486 T3191 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica1] Registered new searcher Searcher@3b32509b[solrj_collection_shard2_replica1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 559486 T3165 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@11f932d4
[junit4] 2> 559485 T3179 oasc.SolrCore.<init> [solrj_collection_shard1_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391956619637/solrj_collection_shard1_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391956619637/solrj_collection_shard1_replica2/data/
[junit4] 2> 559485 T3150 oass.SolrIndexSearcher.<init> Opening Searcher@6e4d2dd8[solrj_collection_shard2_replica2] main
[junit4] 2> 559486 T3165 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391956618469/solrj_collection_shard1_replica1/data
[junit4] 2> 559486 T3179 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@11f932d4
[junit4] 2> 559487 T3165 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391956618469/solrj_collection_shard1_replica1/data/index/
[junit4] 2> 559487 T3119 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica1
[junit4] 2> 559488 T3119 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica1 address:http://127.0.0.1:57325 collection:solrj_collection shard:shard2
[junit4] 2> 559488 T3190 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica2] Registered new searcher Searcher@6e4d2dd8[solrj_collection_shard2_replica2] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 559487 T3179 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391956619637/solrj_collection_shard1_replica2/data
[junit4] 2> 559488 T3179 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391956619637/solrj_collection_shard1_replica2/data/index/
[junit4] 2> 559487 T3165 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica1] Solr index directory '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391956618469/solrj_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4] 2> 559489 T3150 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica2
[junit4] 2> 559489 T3179 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391956619637/solrj_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4] 2> 559489 T3119 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard2/election
[junit4] 2> 559490 T3179 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391956619637/solrj_collection_shard1_replica2/data/index
[junit4] 2> 559489 T3150 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica2 address:http://127.0.0.1:49763 collection:solrj_collection shard:shard2
[junit4] 2> 559490 T3179 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=228034222, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 559489 T3165 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391956618469/solrj_collection_shard1_replica1/data/index
[junit4] 2> 559491 T3179 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1a5ce38c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5f111836),segFN=segments_1,generation=1}
[junit4] 2> 559491 T3179 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 559491 T3165 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=228034222, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 559492 T3150 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard2/election
[junit4] 2> 559492 T3165 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@79d34c78 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@275c8f6),segFN=segments_1,generation=1}
[junit4] 2> 559492 T3165 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 559493 T3179 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 559494 T3179 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 559494 T3179 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 559494 T3179 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 559494 T3179 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 559494 T3179 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 559495 T3179 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 559495 T3165 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 559495 T3179 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 559495 T3179 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 559495 T3165 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 559496 T3179 oasc.RequestHandlers.
[...truncated too long message...]
> "replicationFactor":"2",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2"}
[junit4] 2> 631671 T3233 oasc.SolrException.log ERROR Collection createcollection of createcollection failed:org.apache.solr.common.SolrException: collection already exists: nodes_used_collection
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.createCollection(OverseerCollectionProcessor.java:1541)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.processMessage(OverseerCollectionProcessor.java:385)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:198)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 631674 T3156 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4] 2> 631674 T3233 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000024 complete, response:{Operation createcollection caused exception:=org.apache.solr.common.SolrException: collection already exists: nodes_used_collection,exception={msg=collection already exists: nodes_used_collection,rspCode=400}}
[junit4] 2> 631678 T3098 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4] 2> 631729 T3098 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 49763
[junit4] 2> 631729 T3098 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1724642602
[junit4] 2> 631734 T3184 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 631735 T3170 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:47250_
[junit4] 2> 631735 T3170 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 631737 T3170 oasc.Overseer.start Overseer (id=91223268751310860-127.0.0.1:47250_-n_0000000003) starting
[junit4] 2> 631740 T3235 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 631741 T3170 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 631742 T3235 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 631745 T3234 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 631755 T3098 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4] 2> 631807 T3098 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 47250
[junit4] 2> 631807 T3098 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1691962750
[junit4] 2> 631810 T3170 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 631810 T3184 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 631811 T3184 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:37226_
[junit4] 2> 631812 T3184 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 631813 T3184 oasc.Overseer.start Overseer (id=91223268751310862-127.0.0.1:37226_-n_0000000004) starting
[junit4] 2> 631817 T3237 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 631818 T3237 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 631818 T3236 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 631831 T3098 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4] 2> 631882 T3098 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 37226
[junit4] 2> 631882 T3098 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=2005852241
[junit4] 2> 631907 T3098 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4] 2> 631960 T3098 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 631962 T3098 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:60308 60308
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=EC497D9642030185 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_CU -Dtests.timezone=America/Kralendijk -Dtests.file.encoding=UTF-8
[junit4] ERROR 79.3s J0 | CollectionsAPIDistributedZkTest.testDistribSearch <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: createcollection the collection time out:60s
[junit4] > at __randomizedtesting.SeedInfo.seed([EC497D9642030185:6DAFF38E355C61B9]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:495)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testNodesUsedByCreate(CollectionsAPIDistributedZkTest.java:589)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:201)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:867)
[junit4] > at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 632023 T3098 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 79352 T3097 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 4 leaked thread(s).
[junit4] 2> 633083 T3124 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 633234 T3156 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 633385 T3184 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Asserting, sim=DefaultSimilarity, locale=es_CU, timezone=America/Kralendijk
[junit4] 2> NOTE: Linux 3.8.0-35-generic amd64/Oracle Corporation 1.8.0 (64-bit)/cpus=8,threads=1,free=96136720,total=304128000
[junit4] 2> NOTE: All tests run in this JVM: [ZkCLITest, DateMathParserTest, PolyFieldTest, QueryFacetTest, EchoParamsTest, TestClassNameShortening, LegacyHTMLStripCharFilterTest, TestBM25SimilarityFactory, TestLRUCache, TestPerFieldSimilarity, DeleteShardTest, ScriptEngineTest, TestMergePolicyConfig, TestNoOpRegenerator, SliceStateTest, DocumentBuilderTest, DistributedSuggestComponentTest, TestJmxMonitoredMap, SolrInfoMBeanTest, QueryParsingTest, RegexBoostProcessorTest, TestDynamicFieldCollectionResource, DistributedQueryElevationComponentTest, TestSolrIndexConfig, DirectUpdateHandlerOptimizeTest, TestCharFilters, TestSuggestSpellingConverter, TestSearchPerf, LoggingHandlerTest, TestSolrQueryParserDefaultOperatorResource, SuggesterFSTTest, SynonymTokenizerTest, DistributedSpellCheckComponentTest, FieldMutatingUpdateProcessorTest, LeaderElectionTest, TestRealTimeGet, ResponseLogComponentTest, StatelessScriptUpdateProcessorFactoryTest, TestBadConfig, SpellPossibilityIteratorTest, TestRandomDVFaceting, TestStressVersions, CursorMarkTest, ReturnFieldsTest, ResourceLoaderTest, SolrIndexSplitterTest, TestDocBasedVersionConstraints, QueryResultKeyTest, SampleTest, UnloadDistributedZkTest, TestInfoStreamLogging, ZkControllerTest, CoreAdminCreateDiscoverTest, TestSolrDeletionPolicy1, TestTrie, ShardRoutingTest, TestFunctionQuery, IndexSchemaTest, TestDocSet, TermsComponentTest, ParsingFieldUpdateProcessorsTest, HdfsBasicDistributedZk2Test, SearchHandlerTest, HdfsUnloadDistributedZkTest, TestNonNRTOpen, UpdateParamsTest, BasicFunctionalityTest, TestQueryUtils, TestSystemIdResolver, TestCursorMarkWithoutUniqueKey, DOMUtilTest, AnalysisAfterCoreReloadTest, TestDefaultSearchFieldResource, ExternalFileFieldSortTest, SchemaVersionSpecificBehaviorTest, HdfsChaosMonkeySafeLeaderTest, TestReversedWildcardFilterFactory, QueryElevationComponentTest, FastVectorHighlighterTest, BinaryUpdateRequestHandlerTest, TestShardHandlerFactory, MBeansHandlerTest, BlockDirectoryTest, TestRemoteStreaming, SuggesterTest, SoftAutoCommitTest, TestSolrQueryParser, LukeRequestHandlerTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, CollectionsAPIDistributedZkTest]
[junit4] Completed on J0 in 80.89s, 1 test, 1 error <<< FAILURES!
[...truncated 689 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:453: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:433: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1268: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:901: There were test failures: 370 suites, 1599 tests, 1 error, 35 ignored (7 assumptions)
Total time: 48 minutes 29 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0-fcs-b128 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure