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 2013/11/24 02:06:49 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.6.0_45) - Build # 8341
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/8341/
Java: 64bit/jdk1.6.0_45 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.CustomCollectionTest.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([D39C86FF3DF02781:527A08E74AAF47BD]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:491)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:197)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1597)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1561)
at org.apache.solr.cloud.CustomCollectionTest.testCustomCollectionsAPI(CustomCollectionTest.java:190)
at org.apache.solr.cloud.CustomCollectionTest.doTest(CustomCollectionTest.java:133)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
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:662)
Build Log:
[...truncated 9606 lines...]
[junit4] Suite: org.apache.solr.cloud.CustomCollectionTest
[junit4] 2> 259952 T1762 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 259956 T1762 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-CustomCollectionTest-1385253896496
[junit4] 2> 259957 T1762 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 259957 T1763 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 260057 T1762 oasc.ZkTestServer.run start zk server on port:51002
[junit4] 2> 260058 T1762 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 260177 T1769 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2137fb74 name:ZooKeeperConnection Watcher:127.0.0.1:51002 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 260177 T1762 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 260178 T1762 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 260184 T1762 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 260186 T1771 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@70938cc name:ZooKeeperConnection Watcher:127.0.0.1:51002/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 260186 T1762 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 260187 T1762 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 260191 T1762 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 260195 T1762 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 260199 T1762 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 260202 T1762 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 260203 T1762 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 260210 T1762 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 260210 T1762 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 260215 T1762 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 260216 T1762 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 260220 T1762 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 260221 T1762 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 260225 T1762 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 260225 T1762 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 260229 T1762 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 260229 T1762 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 260233 T1762 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 260234 T1762 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 260238 T1762 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 260239 T1762 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 260243 T1762 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 260243 T1762 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 260247 T1762 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 260247 T1762 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 260251 T1762 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 260252 T1762 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 260315 T1762 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 260317 T1762 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55207
[junit4] 2> 260317 T1762 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 260318 T1762 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 260318 T1762 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1385253896797
[junit4] 2> 260318 T1762 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1385253896797/'
[junit4] 2> 260330 T1762 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1385253896797/solr.xml
[junit4] 2> 260361 T1762 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 260361 T1762 oasc.CoreContainer.<init> New CoreContainer 1064193792
[junit4] 2> 260362 T1762 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1385253896797/]
[junit4] 2> 260363 T1762 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 260363 T1762 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 260363 T1762 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 260363 T1762 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 260364 T1762 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 260364 T1762 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 260364 T1762 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 260365 T1762 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 260365 T1762 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 260366 T1762 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 260366 T1762 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 260367 T1762 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 260367 T1762 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51002/solr
[junit4] 2> 260367 T1762 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 260368 T1762 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 260370 T1782 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6304a988 name:ZooKeeperConnection Watcher:127.0.0.1:51002 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 260370 T1762 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 260373 T1762 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 260375 T1784 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4f16ac7e name:ZooKeeperConnection Watcher:127.0.0.1:51002/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 260375 T1762 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 260377 T1762 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 260382 T1762 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 260386 T1762 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 260389 T1762 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55207_
[junit4] 2> 260390 T1762 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55207_
[junit4] 2> 260395 T1762 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 260402 T1762 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 260406 T1762 oasc.Overseer.start Overseer (id=90783999360958467-127.0.0.1:55207_-n_0000000000) starting
[junit4] 2> 260411 T1762 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 260416 T1786 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 260417 T1762 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 260421 T1762 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 260424 T1762 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 260428 T1785 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 260429 T1762 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1385253896797
[junit4] 2> 260430 T1762 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1385253896797/conf/
[junit4] 2> 260458 T1762 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 260459 T1762 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 260459 T1762 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 260461 T1762 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 260463 T1789 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@44874910 name:ZooKeeperConnection Watcher:127.0.0.1:51002/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 260463 T1762 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 260465 T1762 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 260469 T1762 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 260532 T1762 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 260534 T1762 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51956
[junit4] 2> 260535 T1762 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 260535 T1762 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 260536 T1762 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1385253897009
[junit4] 2> 260536 T1762 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1385253897009/'
[junit4] 2> 260551 T1762 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1385253897009/solr.xml
[junit4] 2> 260581 T1762 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 260581 T1762 oasc.CoreContainer.<init> New CoreContainer 1092022068
[junit4] 2> 260582 T1762 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1385253897009/]
[junit4] 2> 260583 T1762 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 260583 T1762 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 260583 T1762 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 260583 T1762 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 260584 T1762 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 260584 T1762 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 260584 T1762 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 260584 T1762 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 260585 T1762 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 260586 T1762 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 260586 T1762 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 260586 T1762 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 260587 T1762 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51002/solr
[junit4] 2> 260587 T1762 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 260588 T1762 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 260590 T1800 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@48b2604e name:ZooKeeperConnection Watcher:127.0.0.1:51002 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 260590 T1762 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 260594 T1762 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 260595 T1802 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63ac9c80 name:ZooKeeperConnection Watcher:127.0.0.1:51002/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 260595 T1762 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 260601 T1762 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 261606 T1762 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51956_
[junit4] 2> 261607 T1762 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51956_
[junit4] 2> 261611 T1789 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 261612 T1784 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 261612 T1802 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 261618 T1762 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1385253897009
[junit4] 2> 261619 T1762 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1385253897009/conf/
[junit4] 2> 261646 T1762 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 261647 T1762 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 261647 T1762 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 261707 T1762 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 261708 T1762 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:56328
[junit4] 2> 261709 T1762 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 261709 T1762 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 261710 T1762 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CustomCollectionTest-jetty2-1385253898188
[junit4] 2> 261710 T1762 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-jetty2-1385253898188/'
[junit4] 2> 261720 T1762 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1385253898188/solr.xml
[junit4] 2> 261750 T1762 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 261750 T1762 oasc.CoreContainer.<init> New CoreContainer 1844705036
[junit4] 2> 261750 T1762 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CustomCollectionTest-jetty2-1385253898188/]
[junit4] 2> 261751 T1762 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 261752 T1762 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 261752 T1762 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 261752 T1762 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 261753 T1762 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 261753 T1762 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 261753 T1762 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 261754 T1762 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 261754 T1762 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 261755 T1762 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 261755 T1762 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 261756 T1762 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 261756 T1762 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51002/solr
[junit4] 2> 261756 T1762 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 261757 T1762 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 261759 T1814 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2be06d39 name:ZooKeeperConnection Watcher:127.0.0.1:51002 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 261759 T1762 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 261762 T1762 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 261764 T1816 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ad45a89 name:ZooKeeperConnection Watcher:127.0.0.1:51002/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 261764 T1762 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 261769 T1762 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 262773 T1762 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56328_
[junit4] 2> 262775 T1762 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56328_
[junit4] 2> 262781 T1802 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 262781 T1816 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 262782 T1784 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 262782 T1789 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 262789 T1762 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1385253898188
[junit4] 2> 262790 T1762 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1385253898188/conf/
[junit4] 2> 262811 T1762 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 262811 T1762 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 262812 T1762 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 262873 T1762 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 262875 T1762 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:56202
[junit4] 2> 262875 T1762 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 262875 T1762 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 262876 T1762 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1385253899353
[junit4] 2> 262876 T1762 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1385253899353/'
[junit4] 2> 262886 T1762 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1385253899353/solr.xml
[junit4] 2> 262919 T1762 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 262919 T1762 oasc.CoreContainer.<init> New CoreContainer 1349628988
[junit4] 2> 262919 T1762 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1385253899353/]
[junit4] 2> 262920 T1762 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 262921 T1762 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 262921 T1762 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 262921 T1762 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 262922 T1762 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 262922 T1762 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 262922 T1762 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 262922 T1762 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 262923 T1762 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 262924 T1762 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 262924 T1762 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 262925 T1762 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 262925 T1762 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51002/solr
[junit4] 2> 262925 T1762 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 262926 T1762 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 262929 T1828 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58eff866 name:ZooKeeperConnection Watcher:127.0.0.1:51002 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 262929 T1762 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 262932 T1762 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 262934 T1830 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ad79cec name:ZooKeeperConnection Watcher:127.0.0.1:51002/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 262934 T1762 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 262940 T1762 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 263944 T1762 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56202_
[junit4] 2> 263947 T1762 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56202_
[junit4] 2> 263955 T1802 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 263955 T1784 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 263955 T1789 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 263956 T1816 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 263956 T1830 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 263962 T1762 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1385253899353
[junit4] 2> 263963 T1762 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1385253899353/conf/
[junit4] 2> 263991 T1762 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 263991 T1762 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 263991 T1762 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 264050 T1762 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 264053 T1762 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36359
[junit4] 2> 264053 T1762 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 264053 T1762 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 264054 T1762 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1385253900533
[junit4] 2> 264054 T1762 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-jetty4-1385253900533/'
[junit4] 2> 264064 T1762 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1385253900533/solr.xml
[junit4] 2> 264101 T1762 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 264102 T1762 oasc.CoreContainer.<init> New CoreContainer 1520072142
[junit4] 2> 264102 T1762 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CustomCollectionTest-jetty4-1385253900533/]
[junit4] 2> 264103 T1762 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 264103 T1762 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 264104 T1762 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 264104 T1762 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 264104 T1762 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 264105 T1762 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 264105 T1762 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 264105 T1762 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 264105 T1762 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 264107 T1762 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 264107 T1762 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 264107 T1762 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 264108 T1762 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51002/solr
[junit4] 2> 264108 T1762 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 264109 T1762 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 264110 T1842 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@52ac55da name:ZooKeeperConnection Watcher:127.0.0.1:51002 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 264111 T1762 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 264114 T1762 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 264115 T1844 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4be0b391 name:ZooKeeperConnection Watcher:127.0.0.1:51002/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 264116 T1762 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 264121 T1762 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 265126 T1762 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36359_
[junit4] 2> 265127 T1762 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36359_
[junit4] 2> 265135 T1830 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 265135 T1802 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 265136 T1844 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 265136 T1784 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 265137 T1816 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 265137 T1789 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 265143 T1762 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1385253900533
[junit4] 2> 265143 T1762 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1385253900533/conf/
[junit4] 2> 265164 T1762 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 265164 T1762 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 265165 T1762 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 265166 T1762 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 265168 T1847 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ad54694 name:ZooKeeperConnection Watcher:127.0.0.1:51002/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 265168 T1762 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 265170 T1762 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 265174 T1762 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 265175 T1849 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@62d7ab81 name:ZooKeeperConnection Watcher:127.0.0.1:51002/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 265175 T1762 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 265177 T1762 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 265183 T1795 oasha.CollectionsHandler.handleCreateAction Creating Collection : shards=a,b,c&maxShardsPerNode=3&name=implicitcoll0&replicationFactor=3&action=CREATE&wt=javabin&router.name=implicit&version=2
[junit4] 2> 265184 T1784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4] 2> 265185 T1784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4] 2> 265186 T1786 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":"implicitcoll0",
[junit4] 2> "replicationFactor":"3",
[junit4] 2> "maxShardsPerNode":"3",
[junit4] 2> "shards":"a,b,c",
[junit4] 2> "router.name":"implicit"}
[junit4] 2> 265186 T1786 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
[junit4] 2> "operation":"createcollection",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"implicitcoll0",
[junit4] 2> "replicationFactor":"3",
[junit4] 2> "maxShardsPerNode":"3",
[junit4] 2> "shards":"a,b,c",
[junit4] 2> "router.name":"implicit"}
[junit4] 2> 265189 T1784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 265191 T1785 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 265191 T1785 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: implicitcoll0
[junit4] 2> 265192 T1785 oasc.Overseer$ClusterStateUpdater.createCollection Create collection implicitcoll0 with shards [a, b, c]
[junit4] 2> 265196 T1784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 265197 T1844 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> 265197 T1784 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> 265197 T1830 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> 265197 T1847 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> 265197 T1802 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> 265198 T1849 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> 265198 T1789 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> 265199 T1816 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> 265289 T1786 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [a, b, c] , repFactor : 3
[junit4] 2> 265289 T1786 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_a_replica1 as part of slice a of collection implicitcoll0 on 127.0.0.1:56202_
[junit4] 2> 265290 T1786 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_a_replica2 as part of slice a of collection implicitcoll0 on 127.0.0.1:51956_
[junit4] 2> 265290 T1786 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_a_replica3 as part of slice a of collection implicitcoll0 on 127.0.0.1:36359_
[junit4] 2> 265291 T1786 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_b_replica1 as part of slice b of collection implicitcoll0 on 127.0.0.1:55207_
[junit4] 2> 265291 T1786 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_b_replica2 as part of slice b of collection implicitcoll0 on 127.0.0.1:56328_
[junit4] 2> 265293 T1786 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_b_replica3 as part of slice b of collection implicitcoll0 on 127.0.0.1:56202_
[junit4] 2> 265293 T1837 oasc.ZkController.publish publishing core=implicitcoll0_a_replica3 state=down
[junit4] 2> 265293 T1798 oasc.ZkController.publish publishing core=implicitcoll0_a_replica2 state=down
[junit4] 2> 265293 T1825 oasc.ZkController.publish publishing core=implicitcoll0_a_replica1 state=down
[junit4] 2> 265295 T1824 oasc.ZkController.publish publishing core=implicitcoll0_b_replica3 state=down
[junit4] 2> 265294 T1810 oasc.ZkController.publish publishing core=implicitcoll0_b_replica2 state=down
[junit4] 2> 265294 T1777 oasc.ZkController.publish publishing core=implicitcoll0_b_replica1 state=down
[junit4] 2> 265293 T1786 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_c_replica1 as part of slice c of collection implicitcoll0 on 127.0.0.1:51956_
[junit4] 2> 265296 T1784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 265296 T1786 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_c_replica2 as part of slice c of collection implicitcoll0 on 127.0.0.1:36359_
[junit4] 2> 265296 T1786 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_c_replica3 as part of slice c of collection implicitcoll0 on 127.0.0.1:55207_
[junit4] 2> 265297 T1798 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 265297 T1797 oasc.ZkController.publish publishing core=implicitcoll0_c_replica1 state=down
[junit4] 2> 265297 T1837 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 265298 T1810 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 265298 T1777 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 265298 T1839 oasc.ZkController.publish publishing core=implicitcoll0_c_replica2 state=down
[junit4] 2> 265298 T1825 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 265300 T1778 oasc.ZkController.publish publishing core=implicitcoll0_c_replica3 state=down
[junit4] 2> 265301 T1797 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 265300 T1824 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 265301 T1784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 265302 T1839 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 265302 T1778 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 265303 T1785 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 265304 T1785 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:56202",
[junit4] 2> "core":"implicitcoll0_a_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:56202_",
[junit4] 2> "shard":"a",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"implicitcoll0",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 265308 T1785 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:51956",
[junit4] 2> "core":"implicitcoll0_a_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:51956_",
[junit4] 2> "shard":"a",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"implicitcoll0",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 265311 T1784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 265313 T1785 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:36359",
[junit4] 2> "core":"implicitcoll0_a_replica3",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:36359_",
[junit4] 2> "shard":"a",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"implicitcoll0",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 265316 T1784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 265318 T1785 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:56202",
[junit4] 2> "core":"implicitcoll0_b_replica3",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:56202_",
[junit4] 2> "shard":"b",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"implicitcoll0",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 265321 T1784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 265322 T1785 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:56328",
[junit4] 2> "core":"implicitcoll0_b_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:56328_",
[junit4] 2> "shard":"b",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"implicitcoll0",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 265326 T1784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 265328 T1785 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:55207",
[junit4] 2> "core":"implicitcoll0_b_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55207_",
[junit4] 2> "shard":"b",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"implicitcoll0",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 265331 T1784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 265333 T1785 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:51956",
[junit4] 2> "core":"implicitcoll0_c_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:51956_",
[junit4] 2> "shard":"c",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"implicitcoll0",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 265337 T1784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 265339 T1785 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:36359",
[junit4] 2> "core":"implicitcoll0_c_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:36359_",
[junit4] 2> "shard":"c",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"implicitcoll0",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 265342 T1784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 265344 T1785 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:55207",
[junit4] 2> "core":"implicitcoll0_c_replica3",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55207_",
[junit4] 2> "shard":"c",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"implicitcoll0",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 265347 T1784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 265450 T1784 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> 265450 T1844 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> 265450 T1802 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> 265450 T1847 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> 265451 T1830 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> 265451 T1789 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> 265451 T1849 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> 265452 T1816 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> 266298 T1798 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_a_replica2
[junit4] 2> 266298 T1837 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_a_replica3
[junit4] 2> 266299 T1777 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_b_replica1
[junit4] 2> 266299 T1810 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_b_replica2
[junit4] 2> 266300 T1837 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_a_replica3' using instanceDir: ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1385253900533/implicitcoll0_a_replica3
[junit4] 2> 266301 T1777 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_b_replica1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1385253896797/implicitcoll0_b_replica1
[junit4] 2> 266301 T1777 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
[junit4] 2> 266299 T1798 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_a_replica2' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1385253897009/implicitcoll0_a_replica2
[junit4] 2> 266302 T1798 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
[junit4] 2> 266301 T1824 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_b_replica3
[junit4] 2> 266301 T1797 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_c_replica1
[junit4] 2> 266301 T1810 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_b_replica2' using instanceDir: ./org.apache.solr.cloud.CustomCollectionTest-jetty2-1385253898188/implicitcoll0_b_replica2
[junit4] 2> 266303 T1778 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_c_replica3
[junit4] 2> 266301 T1837 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
[junit4] 2> 266300 T1825 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_a_replica1
[junit4] 2> 266304 T1778 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_c_replica3' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1385253896797/implicitcoll0_c_replica3
[junit4] 2> 266304 T1837 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
[junit4] 2> 266304 T1825 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_a_replica1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1385253899353/implicitcoll0_a_replica1
[junit4] 2> 266304 T1837 oasc.ZkController.getConfName Looking for collection configName
[junit4] 2> 266304 T1778 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
[junit4] 2> 266303 T1797 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_c_replica1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1385253897009/implicitcoll0_c_replica1
[junit4] 2> 266305 T1797 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
[junit4] 2> 266303 T1810 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
[junit4] 2> 266303 T1798 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
[junit4] 2> 266303 T1824 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_b_replica3' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1385253899353/implicitcoll0_b_replica3
[junit4] 2> 266307 T1824 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
[junit4] 2> 266307 T1797 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
[junit4] 2> 266302 T1839 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_c_replica2
[junit4] 2> 266302 T1777 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
[junit4] 2> 266308 T1839 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_c_replica2' using instanceDir: ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1385253900533/implicitcoll0_c_replica2
[junit4] 2> 266308 T1839 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
[junit4] 2> 266308 T1837 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4] 2> 266308 T1777 oasc.ZkController.getConfName Looking for collection configName
[junit4] 2> 266307 T1810 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
[junit4] 2> 266309 T1810 oasc.ZkController.getConfName Looking for collection configName
[junit4] 2> 266307 T1797 oasc.ZkController.getConfName Looking for collection configName
[junit4] 2> 266307 T1778 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
[junit4] 2> 266306 T1798 oasc.ZkController.getConfName Looking for collection configName
[junit4] 2> 266305 T1825 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
[junit4] 2> 266310 T1778 oasc.ZkController.getConfName Looking for collection configName
[junit4] 2> 266309 T1839 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
[junit4] 2> 266309 T1837 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
[junit4] 2> 266308 T1824 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
[junit4] 2> 266311 T1839 oasc.ZkController.getConfName Looking for collection configName
[junit4] 2> 266312 T1825 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
[junit4] 2> 266312 T1824 oasc.ZkController.getConfName Looking for collection configName
[junit4] 2> 266312 T1825 oasc.ZkController.getConfName Looking for collection configName
[junit4] 2> 266313 T1777 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4] 2> 266313 T1810 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4] 2> 266314 T1797 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4] 2> 266313 T1777 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
[junit4] 2> 266314 T1797 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
[junit4] 2> 266314 T1810 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
[junit4] 2> 266315 T1798 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4] 2> 266315 T1798 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
[junit4] 2> 266317 T1824 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4] 2> 266317 T1824 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
[junit4] 2> 266318 T1825 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4] 2> 266319 T1825 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
[junit4] 2> 266322 T1797 oascc.ZkStateReader.readConfigName Load collection config from:/collections/implicitcoll0
[junit4] 2> 266322 T1778 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4] 2> 266323 T1810 oascc.ZkStateReader.readConfigName Load collection config from:/collections/implicitcoll0
[junit4] 2> 266323 T1839 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4] 2> 266323 T1778 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
[junit4] 2> 266323 T1798 oascc.ZkStateReader.readConfigName Load collection config from:/collections/implicitcoll0
[junit4] 2> 266323 T1839 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
[junit4] 2> 266325 T1837 oascc.ZkStateReader.readConfigName Load collection config from:/collections/implicitcoll0
[junit4] 2> 266326 T1824 oascc.ZkStateReader.readConfigName Load collection config from:/collections/implicitcoll0
[junit4] 2> 266327 T1810 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-jetty2-1385253898188/implicitcoll0_b_replica2/'
[junit4] 2> 266327 T1825 oascc.ZkStateReader.readConfigName Load collection config from:/collections/implicitcoll0
[junit4] 2> 266327 T1797 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1385253897009/implicitcoll0_c_replica1/'
[junit4] 2> 266330 T1798 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1385253897009/implicitcoll0_a_replica2/'
[junit4] 2> 266330 T1777 oascc.ZkStateReader.readConfigName Load collection config from:/collections/implicitcoll0
[junit4] 2> 266332 T1837 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-jetty4-1385253900533/implicitcoll0_a_replica3/'
[junit4] 2> 266333 T1839 oascc.ZkStateReader.readConfigName Load collection config from:/collections/implicitcoll0
[junit4] 2> 266333 T1824 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1385253899353/implicitcoll0_b_replica3/'
[junit4] 2> 266335 T1825 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1385253899353/implicitcoll0_a_replica1/'
[junit4] 2> 266336 T1778 oascc.ZkStateReader.readConfigName Load collection config from:/collections/implicitcoll0
[junit4] 2> 266337 T1777 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1385253896797/implicitcoll0_b_replica1/'
[junit4] 2> 266341 T1839 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-jetty4-1385253900533/implicitcoll0_c_replica2/'
[junit4] 2> 266341 T1778 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1385253896797/implicitcoll0_c_replica3/'
[junit4] 2> 266386 T1810 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 266416 T1825 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 266423 T1797 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 266426 T1839 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 266432 T1778 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 266434 T1824 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 266439 T1798 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 266439 T1837 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 266447 T1777 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 266491 T1839 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 266495 T1839 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 266496 T1810 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 266500 T1810 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 266506 T1797 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 266508 T1839 oass.IndexSchema.readSchema [implicitcoll0_c_replica2] Schema name=test
[junit4] 2> 266510 T1797 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 266512 T1825 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 266514 T1810 oass.IndexSchema.readSchema [implicitcoll0_b_replica2] Schema name=test
[junit4] 2> 266518 T1798 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 266521 T1798 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 266521 T1825 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 266532 T1797 oass.IndexSchema.readSchema [implicitcoll0_c_replica1] Schema name=test
[junit4] 2> 266538 T1825 oass.IndexSchema.readSchema [implicitcoll0_a_replica1] Schema name=test
[junit4] 2> 266548 T1798 oass.IndexSchema.readSchema [implicitcoll0_a_replica2] Schema name=test
[junit4] 2> 266549 T1778 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 266553 T1778 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 266554 T1824 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 266557 T1824 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 266564 T1777 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 266567 T1778 oass.IndexSchema.readSchema [implicitcoll0_c_replica3] Schema name=test
[junit4] 2> 266567 T1837 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 266570 T1824 oass.IndexSchema.readSchema [implicitcoll0_b_replica3] Schema name=test
[junit4] 2> 266571 T1777 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 266581 T1837 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 266587 T1777 oass.IndexSchema.readSchema [implicitcoll0_b_replica1] Schema name=test
[junit4] 2> 266605 T1837 oass.IndexSchema.readSchema [implicitcoll0_a_replica3] Schema name=test
[junit4] 2> 267306 T1810 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 267306 T1810 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 267307 T1810 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 267318 T1810 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 267323 T1810 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 267359 T1810 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 267365 T1810 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 267384 T1810 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 267397 T1810 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 267397 T1810 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 267398 T1810 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 267400 T1810 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 267401 T1810 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 267401 T1810 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 267402 T1810 oasc.SolrCore.<init> [implicitcoll0_b_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CustomCollectionTest-jetty2-1385253898188/implicitcoll0_b_replica2/, dataDir=./org.apache.solr.cloud.CustomCollectionTest-jetty2-1385253898188/implicitcoll0_b_replica2/data/
[junit4] 2> 267402 T1810 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@62a28815
[junit4] 2> 267408 T1810 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CustomCollectionTest-jetty2-1385253898188/implicitcoll0_b_replica2/data
[junit4] 2> 267409 T1810 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CustomCollectionTest-jetty2-1385253898188/implicitcoll0_b_replica2/data/index/
[junit4] 2> 267410 T1810 oasc.SolrCore.initIndex WARN [implicitcoll0_b_replica2] Solr index directory './org.apache.solr.cloud.CustomCollectionTest-jetty2-1385253898188/implicitcoll0_b_replica2/data/index' doesn't exist. Creating new index...
[junit4] 2> 267417 T1810 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CustomCollectionTest-jetty2-1385253898188/implicitcoll0_b_replica2/data/index
[junit4] 2> 267418 T1810 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=44, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5998182623493257]
[junit4] 2> 267419 T1810 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@3fb90b1b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@262d2c7d),segFN=segments_1,generation=1}
[junit4] 2> 267420 T1810 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 267425 T1810 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 267426 T1810 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 267426 T1810 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 267427 T1810 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 267427 T1810 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 267428 T1810 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 267429 T1810 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 267429 T1810 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 267429 T1810 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 267430 T1810 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 267431 T1810 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 267432 T1810 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 267432 T1810 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 267433 T1810 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 267434 T1810 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 267434 T1798 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 267434 T1810 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 267434 T1798 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 267437 T1810 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 267439 T1798 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 267440 T1825 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 267440 T1825 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 267441 T1825 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 267442 T1810 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 267442 T1810 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 267443 T1810 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=11, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3536031305202032]
[junit4] 2> 267444 T1810 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@3fb90b1b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@262d2c7d),segFN=segments_1,generation=1}
[junit4] 2> 267445 T1810 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 267445 T1810 oass.SolrIndexSearcher.<init> Opening Searcher@7e9caac main
[junit4] 2> 267450 T1859 oasc.SolrCore.registerSearcher [implicitcoll0_b_replica2] Registered new searcher Searcher@7e9caac main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 267452 T1825 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 267453 T1810 oasc.CoreContainer.registerCore registering core: implicitcoll0_b_replica2
[junit4] 2> 267454 T1810 oasc.ZkController.register Register replica - core:implicitcoll0_b_replica2 address:http://127.0.0.1:56328 collection:implicitcoll0 shard:b
[junit4] 2> 267456 T1798 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 267457 T1825 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 267459 T1778 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 267460 T1778 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 267461 T1778 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 267461 T1798 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 267461 T1810 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0/leader_elect/b/election
[junit4] 2> 267473 T1778 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 267473 T1839 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 267474 T1839 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 267475 T1839 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 267478 T1778 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 267480 T1810 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard b
[junit4] 2> 267486 T1839 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 267486 T1824 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 267487 T1824 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 267488 T1824 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 267489 T1784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 267490 T1784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 267490 T1784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 267491 T1839 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 267492 T1810 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard b: total=3 found=1 timeoutin=179999
[junit4] 2> 267507 T1785 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 267509 T1824 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 267513 T1824 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 267513 T1825 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 267525 T1797 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 267525 T1797 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 267526 T1797 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 267531 T1825 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 267535 T1777 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 267535 T1777 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 267536 T1784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 267536 T1777 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 267537 T1825 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 267538 T1797 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 267538 T1784 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> 267541 T1789 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> 267542 T1849 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> 267542 T1816 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> 267542 T1847 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> 267542 T1797 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 267544 T1777 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 267544 T1844 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> 267545 T1802 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> 267547 T1777 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 267547 T1830 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> 267551 T1825 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 267551 T1825 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 267552 T1825 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 267556 T1839 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 267558 T1825 oass.OpenExchangeRatesOrgProvider$OpenExchangeRat
[...truncated too long message...]
1762 oasc.SolrCore.close [implicitcoll3_c_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@6c9f55d2
[junit4] 2> 472913 T1762 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
[junit4] 2> 472913 T1762 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 472914 T1762 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 472914 T1762 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 472915 T1762 oasc.SolrCore.closeSearcher [implicitcoll3_c_replica1] Closing main searcher on request.
[junit4] 2> 472915 T1762 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 472915 T1762 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1385253900533/implicitcoll3_c_replica1/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CustomCollectionTest-jetty4-1385253900533/implicitcoll3_c_replica1/data;done=false>>]
[junit4] 2> 472916 T1762 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1385253900533/implicitcoll3_c_replica1/data
[junit4] 2> 472916 T1762 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1385253900533/implicitcoll3_c_replica1/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CustomCollectionTest-jetty4-1385253900533/implicitcoll3_c_replica1/data/index;done=false>>]
[junit4] 2> 472916 T1762 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1385253900533/implicitcoll3_c_replica1/data/index
[junit4] 2> 472916 T1762 oasc.SolrCore.close [implicitcoll4_a_replica3] CLOSING SolrCore org.apache.solr.core.SolrCore@70d898be
[junit4] 2> 472925 T1762 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
[junit4] 2> 472925 T1762 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 472926 T1762 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 472926 T1762 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 472926 T1762 oasc.SolrCore.closeSearcher [implicitcoll4_a_replica3] Closing main searcher on request.
[junit4] 2> 472927 T1762 oasc.CachingDirectoryFactory.close Closing RAMDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 472927 T1762 oasc.CachingDirectoryFactory.closeCacheValue looking to close data/index [CachedDir<<refCount=0;path=data/index;done=false>>]
[junit4] 2> 472927 T1762 oasc.CachingDirectoryFactory.close Closing directory: data/index
[junit4] 2> 472927 T1762 oasc.CachingDirectoryFactory.closeCacheValue looking to close data [CachedDir<<refCount=0;path=data;done=false>>]
[junit4] 2> 472928 T1762 oasc.CachingDirectoryFactory.close Closing directory: data
[junit4] 2> 472928 T1762 oasc.SolrCore.close [implicitcoll4_c_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@507f51dd
[junit4] 2> 472936 T1762 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
[junit4] 2> 472936 T1762 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 472936 T1762 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 472937 T1762 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 472937 T1762 oasc.SolrCore.closeSearcher [implicitcoll4_c_replica1] Closing main searcher on request.
[junit4] 2> 472938 T1762 oasc.CachingDirectoryFactory.close Closing RAMDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 472938 T1762 oasc.CachingDirectoryFactory.closeCacheValue looking to close data/index [CachedDir<<refCount=0;path=data/index;done=false>>]
[junit4] 2> 472938 T1762 oasc.CachingDirectoryFactory.close Closing directory: data/index
[junit4] 2> 472939 T1762 oasc.CachingDirectoryFactory.closeCacheValue looking to close data [CachedDir<<refCount=0;path=data;done=false>>]
[junit4] 2> 472939 T1762 oasc.CachingDirectoryFactory.close Closing directory: data
[junit4] 2> 472963 T1762 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4] 2> 473018 T1762 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 473021 T1762 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:51002 51002
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CustomCollectionTest -Dtests.method=testDistribSearch -Dtests.seed=D39C86FF3DF02781 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=tr -Dtests.timezone=Pacific/Wallis -Dtests.file.encoding=UTF-8
[junit4] ERROR 213s J0 | CustomCollectionTest.testDistribSearch <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: createcollection the collection time out:60s
[junit4] > at __randomizedtesting.SeedInfo.seed([D39C86FF3DF02781:527A08E74AAF47BD]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:491)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:197)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1597)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1561)
[junit4] > at org.apache.solr.cloud.CustomCollectionTest.testCustomCollectionsAPI(CustomCollectionTest.java:190)
[junit4] > at org.apache.solr.cloud.CustomCollectionTest.doTest(CustomCollectionTest.java:133)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:662)
[junit4] 2> 473256 T1762 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 213311 T1761 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4] 2> 474443 T1844 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene42, sim=DefaultSimilarity, locale=tr, timezone=Pacific/Wallis
[junit4] 2> NOTE: Linux 3.8.0-33-generic amd64/Sun Microsystems Inc. 1.6.0_45 (64-bit)/cpus=8,threads=1,free=119338456,total=297074688
[junit4] 2> NOTE: All tests run in this JVM: [TestShardHandlerFactory, TestBM25SimilarityFactory, TestConfig, HdfsDirectoryTest, TestSurroundQueryParser, TestFieldCollectionResource, ScriptEngineTest, TestSimpleQParserPlugin, TestSystemIdResolver, PrimitiveFieldTypeTest, DOMUtilTest, TestImplicitCoreProperties, HdfsBasicDistributedZk2Test, StatelessScriptUpdateProcessorFactoryTest, TestPerFieldSimilarity, SystemInfoHandlerTest, ShardRoutingTest, HdfsLockFactoryTest, SampleTest, TestMaxScoreQueryParser, TestDynamicFieldCollectionResource, ClusterStateTest, TriLevelCompositeIdRoutingTest, TestLMJelinekMercerSimilarityFactory, OverseerCollectionProcessorTest, TestDocSet, SuggestComponentTest, UUIDFieldTest, CSVRequestHandlerTest, TestReversedWildcardFilterFactory, TestLRUCache, TestWriterPerf, DeleteInactiveReplicaTest, TestReplicationHandler, CustomCollectionTest]
[junit4] Completed on J0 in 214.59s, 1 test, 1 error <<< FAILURES!
[...truncated 838 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:426: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:406: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:492: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1276: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:912: There were test failures: 345 suites, 1505 tests, 1 error, 34 ignored (6 assumptions)
Total time: 48 minutes 58 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.6.0_45 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.7.0_45) - Build # 8342
- Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/8342/
Java: 32bit/jdk1.7.0_45 -client -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.SyncSliceTest.testDistribSearch
Error Message:
timeout waiting to see recovered node
Stack Trace:
java.lang.AssertionError: timeout waiting to see recovered node
at __randomizedtesting.SeedInfo.seed([7A9509DF59666FB2:FB7387C72E390F8E]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.SyncSliceTest.waitTillRecovered(SyncSliceTest.java:265)
at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:188)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
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 10541 lines...]
[junit4] Suite: org.apache.solr.cloud.SyncSliceTest
[junit4] 2> 922281 T2712 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_/i
[junit4] 2> 922285 T2712 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-SyncSliceTest-1385260405158
[junit4] 2> 922285 T2712 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 922286 T2713 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 922386 T2712 oasc.ZkTestServer.run start zk server on port:49380
[junit4] 2> 922387 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 922479 T2719 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1579dcd name:ZooKeeperConnection Watcher:127.0.0.1:49380 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 922480 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 922480 T2712 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 922484 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 922485 T2721 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a98298 name:ZooKeeperConnection Watcher:127.0.0.1:49380/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 922485 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 922485 T2712 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 922487 T2712 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 922489 T2712 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 922490 T2712 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 922492 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 922492 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 922495 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 922495 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 922499 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 922499 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 922502 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 922502 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 922504 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 922505 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 922506 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 922507 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 922509 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 922510 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 922513 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 922514 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 922516 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 922516 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 922520 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 922521 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 922523 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 922523 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 922592 T2712 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 922596 T2712 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:34416
[junit4] 2> 922597 T2712 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 922597 T2712 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 922598 T2712 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.SyncSliceTest-controljetty-1385260405398
[junit4] 2> 922598 T2712 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-controljetty-1385260405398/'
[junit4] 2> 922611 T2712 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-1385260405398/solr.xml
[junit4] 2> 922654 T2712 oasc.CoreContainer.<init> New CoreContainer 3613628
[junit4] 2> 922655 T2712 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.SyncSliceTest-controljetty-1385260405398/]
[junit4] 2> 922656 T2712 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 922656 T2712 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 922656 T2712 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 922656 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 922657 T2712 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 922657 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 922657 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 922658 T2712 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 922658 T2712 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 922659 T2712 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 922659 T2712 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 922660 T2712 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 922660 T2712 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49380/solr
[junit4] 2> 922660 T2712 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 922661 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 922662 T2732 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e83e20 name:ZooKeeperConnection Watcher:127.0.0.1:49380 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 922663 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 922665 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 922666 T2734 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14d2181 name:ZooKeeperConnection Watcher:127.0.0.1:49380/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 922666 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 922668 T2712 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 922670 T2712 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 922673 T2712 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 922674 T2712 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34416__%2Fi
[junit4] 2> 922675 T2712 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:34416__%2Fi
[junit4] 2> 922677 T2712 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 922681 T2712 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 922683 T2712 oasc.Overseer.start Overseer (id=90784425912565763-127.0.0.1:34416__%2Fi-n_0000000000) starting
[junit4] 2> 922685 T2712 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 922688 T2736 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 922689 T2712 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 922691 T2712 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 922693 T2712 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 922695 T2735 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 922698 T2737 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 922698 T2737 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 922699 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 922699 T2737 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 922700 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 922701 T2735 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:34416/_/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:34416__%2Fi",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 922701 T2735 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 922701 T2735 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 922703 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 922704 T2734 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 923699 T2737 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 923700 T2737 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.SyncSliceTest-controljetty-1385260405398/collection1
[junit4] 2> 923700 T2737 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 923701 T2737 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 923701 T2737 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 923703 T2737 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-controljetty-1385260405398/collection1/'
[junit4] 2> 923704 T2737 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-controljetty-1385260405398/collection1/lib/classes/' to classloader
[junit4] 2> 923704 T2737 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-controljetty-1385260405398/collection1/lib/README' to classloader
[junit4] 2> 923750 T2737 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 923788 T2737 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 923789 T2737 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 923797 T2737 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 924169 T2737 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 924170 T2737 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 924170 T2737 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 924176 T2737 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 924179 T2737 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 924193 T2737 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 924196 T2737 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 924200 T2737 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 924201 T2737 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 924201 T2737 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 924201 T2737 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 924203 T2737 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 924203 T2737 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 924203 T2737 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 924203 T2737 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.SyncSliceTest-controljetty-1385260405398/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1385260405158/control/data/
[junit4] 2> 924204 T2737 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a4acb0
[junit4] 2> 924204 T2737 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1385260405158/control/data
[junit4] 2> 924205 T2737 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1385260405158/control/data/index/
[junit4] 2> 924205 T2737 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1385260405158/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 924205 T2737 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1385260405158/control/data/index
[junit4] 2> 924206 T2737 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@11ad35a
[junit4] 2> 924206 T2737 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@879323 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8e83fd),segFN=segments_1,generation=1}
[junit4] 2> 924206 T2737 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 924209 T2737 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 924209 T2737 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 924210 T2737 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 924210 T2737 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 924210 T2737 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 924211 T2737 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 924211 T2737 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 924212 T2737 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 924212 T2737 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 924212 T2737 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 924213 T2737 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 924213 T2737 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 924213 T2737 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 924214 T2737 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 924214 T2737 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 924215 T2737 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 924218 T2737 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 924222 T2737 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 924222 T2737 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 924223 T2737 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=41, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=40.4130859375, floorSegmentMB=1.4091796875, forceMergeDeletesPctAllowed=12.721785723941798, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7052138284692118
[junit4] 2> 924223 T2737 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@879323 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8e83fd),segFN=segments_1,generation=1}
[junit4] 2> 924223 T2737 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 924224 T2737 oass.SolrIndexSearcher.<init> Opening Searcher@19603ef main
[junit4] 2> 924227 T2738 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@19603ef main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 924228 T2737 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 924228 T2737 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:34416/_/i collection:control_collection shard:shard1
[junit4] 2> 924229 T2737 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 924234 T2737 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 924235 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 924236 T2737 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 924236 T2737 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1053 name=collection1 org.apache.solr.core.SolrCore@1b37baf url=http://127.0.0.1:34416/_/i/collection1 node=127.0.0.1:34416__%2Fi C1053_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:34416/_/i, core=collection1, node_name=127.0.0.1:34416__%2Fi}
[junit4] 2> 924236 T2737 C1053 P34416 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:34416/_/i/collection1/
[junit4] 2> 924236 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 924237 T2737 C1053 P34416 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 924237 T2737 C1053 P34416 oasc.SyncStrategy.syncToMe http://127.0.0.1:34416/_/i/collection1/ has no replicas
[junit4] 2> 924237 T2737 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:34416/_/i/collection1/ shard1
[junit4] 2> 924237 T2737 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 924239 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 924239 T2734 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 924242 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 924243 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 924245 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 924348 T2734 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 924393 T2737 oasc.ZkController.register We are http://127.0.0.1:34416/_/i/collection1/ and leader is http://127.0.0.1:34416/_/i/collection1/
[junit4] 2> 924393 T2737 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:34416/_/i
[junit4] 2> 924393 T2737 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 924393 T2737 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 924394 T2737 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 924395 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 924395 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 924395 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 924395 T2737 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 924396 T2712 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 924397 T2712 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 924396 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 924397 T2735 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:34416/_/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:34416__%2Fi",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 924398 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 924399 T2741 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a85b5 name:ZooKeeperConnection Watcher:127.0.0.1:49380/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 924400 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 924400 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 924401 T2712 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 924405 T2712 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 924481 T2712 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 924483 T2712 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40182
[junit4] 2> 924485 T2712 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 924485 T2712 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 924486 T2712 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.SyncSliceTest-jetty1-1385260407279
[junit4] 2> 924486 T2712 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-jetty1-1385260407279/'
[junit4] 2> 924502 T2734 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 924502 T2741 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 924507 T2712 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1385260407279/solr.xml
[junit4] 2> 924556 T2712 oasc.CoreContainer.<init> New CoreContainer 2576800
[junit4] 2> 924556 T2712 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.SyncSliceTest-jetty1-1385260407279/]
[junit4] 2> 924557 T2712 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 924557 T2712 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 924558 T2712 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 924558 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 924558 T2712 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 924558 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 924559 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 924559 T2712 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 924559 T2712 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 924560 T2712 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 924561 T2712 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 924561 T2712 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 924561 T2712 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49380/solr
[junit4] 2> 924562 T2712 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 924562 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 924564 T2752 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a4ce66 name:ZooKeeperConnection Watcher:127.0.0.1:49380 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 924565 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 924568 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 924569 T2754 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@46ef9 name:ZooKeeperConnection Watcher:127.0.0.1:49380/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 924570 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 924574 T2712 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 925578 T2712 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40182__%2Fi
[junit4] 2> 925579 T2712 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40182__%2Fi
[junit4] 2> 925582 T2734 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 925582 T2754 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 925582 T2741 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 925588 T2755 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 925588 T2755 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 925589 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 925589 T2755 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 925589 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 925590 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 925591 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 925592 T2735 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:40182/_/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:40182__%2Fi",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 925592 T2735 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 925593 T2735 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 925596 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 925698 T2734 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 925698 T2741 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 925698 T2754 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 926590 T2755 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 926590 T2755 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.SyncSliceTest-jetty1-1385260407279/collection1
[junit4] 2> 926590 T2755 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 926591 T2755 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 926591 T2755 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 926592 T2755 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-jetty1-1385260407279/collection1/'
[junit4] 2> 926593 T2755 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty1-1385260407279/collection1/lib/classes/' to classloader
[junit4] 2> 926593 T2755 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty1-1385260407279/collection1/lib/README' to classloader
[junit4] 2> 926629 T2755 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 926666 T2755 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 926667 T2755 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 926675 T2755 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 927061 T2755 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 927062 T2755 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 927062 T2755 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 927068 T2755 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 927071 T2755 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 927080 T2755 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 927083 T2755 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 927086 T2755 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 927087 T2755 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 927087 T2755 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 927087 T2755 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 927088 T2755 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 927088 T2755 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 927089 T2755 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 927089 T2755 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.SyncSliceTest-jetty1-1385260407279/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty1/
[junit4] 2> 927089 T2755 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a4acb0
[junit4] 2> 927090 T2755 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty1
[junit4] 2> 927090 T2755 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty1/index/
[junit4] 2> 927090 T2755 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 927090 T2755 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty1/index
[junit4] 2> 927091 T2755 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@51cc07
[junit4] 2> 927091 T2755 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@151c152 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d9cc80),segFN=segments_1,generation=1}
[junit4] 2> 927091 T2755 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 927094 T2755 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 927094 T2755 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 927095 T2755 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 927095 T2755 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 927095 T2755 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 927095 T2755 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 927096 T2755 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 927096 T2755 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 927096 T2755 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 927097 T2755 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 927097 T2755 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 927098 T2755 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 927098 T2755 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 927098 T2755 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 927099 T2755 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 927099 T2755 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 927101 T2755 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 927104 T2755 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 927104 T2755 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 927105 T2755 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=41, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=40.4130859375, floorSegmentMB=1.4091796875, forceMergeDeletesPctAllowed=12.721785723941798, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7052138284692118
[junit4] 2> 927105 T2755 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@151c152 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d9cc80),segFN=segments_1,generation=1}
[junit4] 2> 927106 T2755 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 927106 T2755 oass.SolrIndexSearcher.<init> Opening Searcher@1da3472 main
[junit4] 2> 927110 T2756 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1da3472 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 927112 T2755 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 927112 T2755 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:40182/_/i collection:collection1 shard:shard1
[junit4] 2> 927113 T2755 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 927117 T2755 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 927119 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927119 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927119 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927119 T2755 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 927120 T2755 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1054 name=collection1 org.apache.solr.core.SolrCore@8948c url=http://127.0.0.1:40182/_/i/collection1 node=127.0.0.1:40182__%2Fi C1054_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:40182/_/i, core=collection1, node_name=127.0.0.1:40182__%2Fi}
[junit4] 2> 927120 T2755 C1054 P40182 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:40182/_/i/collection1/
[junit4] 2> 927120 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 927120 T2755 C1054 P40182 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 927121 T2755 C1054 P40182 oasc.SyncStrategy.syncToMe http://127.0.0.1:40182/_/i/collection1/ has no replicas
[junit4] 2> 927121 T2755 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:40182/_/i/collection1/ shard1
[junit4] 2> 927121 T2755 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 927123 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927125 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927161 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927263 T2734 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 927263 T2754 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 927263 T2741 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 927276 T2755 oasc.ZkController.register We are http://127.0.0.1:40182/_/i/collection1/ and leader is http://127.0.0.1:40182/_/i/collection1/
[junit4] 2> 927276 T2755 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:40182/_/i
[junit4] 2> 927276 T2755 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 927277 T2755 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 927277 T2755 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 927278 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927278 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927278 T2755 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 927279 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927280 T2712 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 927280 T2712 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 927280 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 927282 T2735 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:40182/_/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:40182__%2Fi",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 927283 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927357 T2712 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 927358 T2712 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:60313
[junit4] 2> 927359 T2712 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 927360 T2712 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 927360 T2712 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1385260410155
[junit4] 2> 927360 T2712 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1385260410155/'
[junit4] 2> 927372 T2712 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1385260410155/solr.xml
[junit4] 2> 927385 T2734 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 927385 T2741 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 927385 T2754 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 927415 T2712 oasc.CoreContainer.<init> New CoreContainer 2474702
[junit4] 2> 927415 T2712 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1385260410155/]
[junit4] 2> 927416 T2712 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 927417 T2712 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 927417 T2712 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 927417 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 927417 T2712 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 927418 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 927418 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 927418 T2712 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 927419 T2712 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 927420 T2712 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 927420 T2712 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 927420 T2712 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 927421 T2712 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49380/solr
[junit4] 2> 927421 T2712 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 927422 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 927424 T2768 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ef42f4 name:ZooKeeperConnection Watcher:127.0.0.1:49380 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 927424 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 927427 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 927427 T2770 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b9033 name:ZooKeeperConnection Watcher:127.0.0.1:49380/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 927428 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 927431 T2712 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 928433 T2712 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60313__%2Fi
[junit4] 2> 928434 T2712 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60313__%2Fi
[junit4] 2> 928437 T2734 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 928437 T2754 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 928437 T2741 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 928437 T2770 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 928442 T2771 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 928443 T2771 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 928539 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 928539 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 928539 T2771 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 928539 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 928541 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 928542 T2735 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:60313/_/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:60313__%2Fi",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 928542 T2735 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 928542 T2735 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 928545 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 928648 T2734 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 928648 T2770 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 928648 T2754 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 928648 T2741 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 929540 T2771 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 929540 T2771 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1385260410155/collection1
[junit4] 2> 929540 T2771 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 929541 T2771 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 929541 T2771 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 929542 T2771 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1385260410155/collection1/'
[junit4] 2> 929543 T2771 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty2-1385260410155/collection1/lib/classes/' to classloader
[junit4] 2> 929544 T2771 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty2-1385260410155/collection1/lib/README' to classloader
[junit4] 2> 929584 T2771 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 929628 T2771 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 929629 T2771 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 929642 T2771 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 930092 T2771 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 930093 T2771 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 930094 T2771 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 930100 T2771 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 930103 T2771 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 930114 T2771 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 930118 T2771 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 930122 T2771 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 930123 T2771 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 930123 T2771 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 930123 T2771 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 930124 T2771 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 930124 T2771 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 930124 T2771 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 930125 T2771 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1385260410155/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty2/
[junit4] 2> 930125 T2771 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a4acb0
[junit4] 2> 930126 T2771 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty2
[junit4] 2> 930126 T2771 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty2/index/
[junit4] 2> 930126 T2771 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 930127 T2771 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty2/index
[junit4] 2> 930127 T2771 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@a02270
[junit4] 2> 930128 T2771 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9974ea lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1df4a7a),segFN=segments_1,generation=1}
[junit4] 2> 930128 T2771 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 930131 T2771 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 930132 T2771 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 930132 T2771 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 930132 T2771 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 930132 T2771 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 930133 T2771 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 930133 T2771 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 930133 T2771 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 930133 T2771 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 930134 T2771 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 930135 T2771 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 930135 T2771 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 930135 T2771 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 930136 T2771 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 930136 T2771 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 930137 T2771 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 930140 T2771 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 930143 T2771 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 930143 T2771 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 930145 T2771 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=41, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=40.4130859375, floorSegmentMB=1.4091796875, forceMergeDeletesPctAllowed=12.721785723941798, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7052138284692118
[junit4] 2> 930145 T2771 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9974ea lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1df4a7a),segFN=segments_1,generation=1}
[junit4] 2> 930145 T2771 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 930146 T2771 oass.SolrIndexSearcher.<init> Opening Searcher@829ef8 main
[junit4] 2> 930152 T2772 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@829ef8 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 930154 T2771 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 930155 T2771 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:60313/_/i collection:collection1 shard:shard1
[junit4] 2> 930158 T2771 oasc.ZkController.register We are http://127.0.0.1:60313/_/i/collection1/ and leader is http://127.0.0.1:40182/_/i/collection1/
[junit4] 2> 930159 T2771 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60313/_/i
[junit4] 2> 930159 T2771 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 930159 T2771 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C1055 name=collection1 org.apache.solr.core.SolrCore@98aa61 url=http://127.0.0.1:60313/_/i/collection1 node=127.0.0.1:60313__%2Fi C1055_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:60313/_/i, core=collection1, node_name=127.0.0.1:60313__%2Fi}
[junit4] 2> 930159 T2773 C1055 P60313 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 930160 T2773 C1055 P60313 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 930160 T2771 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 930160 T2773 C1055 P60313 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 930160 T2773 C1055 P60313 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 930161 T2712 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 930161 T2712 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 930162 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 930162 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 930162 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 930164 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 930164 T2750 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 930164 T2735 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "base_url":"http://127.0.0.1:60313/_/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:60313__%2Fi",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 930167 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 930168 T2741 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 930168 T2734 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 930168 T2770 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 930168 T2754 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 930257 T2712 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 930259 T2712 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:39878
[junit4] 2> 930259 T2712 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 930260 T2712 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 930260 T2712 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.SyncSliceTest-jetty3-1385260413036
[junit4] 2> 930260 T2712 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-jetty3-1385260413036/'
[junit4] 2> 930276 T2712 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1385260413036/solr.xml
[junit4] 2> 930349 T2712 oasc.CoreContainer.<init> New CoreContainer 19826714
[junit4] 2> 930350 T2712 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.SyncSliceTest-jetty3-1385260413036/]
[junit4] 2> 930351 T2712 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 930351 T2712 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 930351 T2712 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 930352 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 930352 T2712 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 930352 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 930353 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 930353 T2712 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 930354 T2712 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 930356 T2712 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 930356 T2712 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 930357 T2712 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 930357 T2712 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49380/solr
[junit4] 2> 930358 T2712 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 930358 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 930359 T2785 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@130a88f name:ZooKeeperConnection Watcher:127.0.0.1:49380 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 930360 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 930363 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 930364 T2787 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@862e21 name:ZooKeeperConnection Watcher:127.0.0.1:49380/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 930364 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 930368 T2712 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 931167 T2750 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 931168 T2750 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=core_node2&state=recovering&nodeName=127.0.0.1:60313__%252Fi&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1004
[junit4] 2> 931370 T2712 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39878__%2Fi
[junit4] 2> 931372 T2712 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39878__%2Fi
[junit4] 2> 931374 T2770 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 931374 T2734 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 931374 T2741 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 931374 T2754 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 931375 T2787 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 931380 T2788 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 931381 T2788 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 931382 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 931382 T2788 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 931383 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 931384 T2735 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:39878/_/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:39878__%2Fi",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 931384 T2735 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 931384 T2735 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 931386 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 931489 T2770 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 931489 T2754 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 931489 T2787 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 931489 T2741 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 931489 T2734 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 932382 T2788 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 932383 T2788 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.SyncSliceTest-jetty3-1385260413036/collection1
[junit4] 2> 932383 T2788 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 932384 T2788 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 932384 T2788 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 932385 T2788 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-jetty3-1385260413036/collection1/'
[junit4] 2> 932386 T2788 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty3-1385260413036/collection1/lib/classes/' to classloader
[junit4] 2> 932386 T2788 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty3-1385260413036/collection1/lib/README' to classloader
[junit4] 2> 932431 T2788 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 932477 T2788 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 932478 T2788 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 932489 T2788 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 932930 T2788 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 932931 T2788 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 932932 T2788 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 932939 T2788 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 932942 T2788 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 932952 T2788 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 932956 T2788 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 932959 T2788 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 932960 T2788 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 932961 T2788 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 932961 T2788 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 932962 T2788 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 932962 T2788 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 932962 T2788 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 932963 T2788 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.SyncSliceTest-jetty3-1385260413036/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty3/
[junit4] 2> 932963 T2788 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a4acb0
[junit4] 2> 932964 T2788 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty3
[junit4] 2> 932964 T2788 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty3/index/
[junit4] 2> 932964 T2788 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 932965 T2788 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty3/index
[junit4] 2> 932965 T2788 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@14e102e
[junit4] 2> 932965 T2788 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@17e5895 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@31b81),segFN=segments_1,generation=1}
[junit4] 2> 932966 T2788 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 932969 T2788 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 932969 T2788 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 932969 T2788 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 932970 T2788 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 932970 T2788 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 932970 T2788 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 932971 T2788 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 932971 T2788 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 932971 T2788 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 932972 T2788 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 932972 T2788 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 932973 T2788 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 932973 T2788 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 932973 T2788 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 932974 T2788 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 932974 T2788 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 932977 T2788 oashl.XMLLoader.init xsltCacheLifetimeSeconds=6
[...truncated too long message...]
"shards":{"shard1":{
[junit4] 1> "range":"80000000-7fffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{"core_node1":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:34416/_/i",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:34416__%2Fi",
[junit4] 1> "leader":"true"}}}},
[junit4] 1> "maxShardsPerNode":"1",
[junit4] 1> "router":{"name":"compositeId"},
[junit4] 1> "replicationFactor":"1",
[junit4] 1> "autoCreated":"true"}}
[junit4] 1> /solr/aliases.json (0)
[junit4] 1> /solr/live_nodes (4)
[junit4] 1> /solr/live_nodes/127.0.0.1:39878__%2Fi (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:54595__%2Fi (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:60313__%2Fi (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:34416__%2Fi (0)
[junit4] 1> /solr/overseer (3)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1> /solr/overseer/queue (0)
[junit4] 1> /solr/overseer/queue-work (0)
[junit4] 1> /solr/overseer/collection-queue-work (0)
[junit4] 1> /solr/collections (2)
[junit4] 1> /solr/collections/collection1 (3)
[junit4] 1> DATA:
[junit4] 1> {"configName":"conf1"}
[junit4] 1> /solr/collections/collection1/shards (0)
[junit4] 1> /solr/collections/collection1/leader_elect (1)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1 (1)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election (3)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90784425912565772-core_node4-n_0000000003 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90784425912565768-core_node2-n_0000000001 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90784425912565770-core_node3-n_0000000002 (0)
[junit4] 1> /solr/collections/collection1/leaders (1)
[junit4] 1> /solr/collections/collection1/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:60313__%2Fi",
[junit4] 1> "base_url":"http://127.0.0.1:60313/_/i"}
[junit4] 1> /solr/collections/control_collection (3)
[junit4] 1> DATA:
[junit4] 1> {"configName":"conf1"}
[junit4] 1> /solr/collections/control_collection/shards (0)
[junit4] 1> /solr/collections/control_collection/leader_elect (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1 (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election/90784425912565763-core_node1-n_0000000000 (0)
[junit4] 1> /solr/collections/control_collection/leaders (1)
[junit4] 1> /solr/collections/control_collection/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:34416__%2Fi",
[junit4] 1> "base_url":"http://127.0.0.1:34416/_/i"}
[junit4] 1> /solr/overseer_elect (2)
[junit4] 1> /solr/overseer_elect/election (4)
[junit4] 1> /solr/overseer_elect/election/90784425912565768-127.0.0.1:60313__%2Fi-n_0000000002 (0)
[junit4] 1> /solr/overseer_elect/election/90784425912565770-127.0.0.1:39878__%2Fi-n_0000000003 (0)
[junit4] 1> /solr/overseer_elect/election/90784425912565763-127.0.0.1:34416__%2Fi-n_0000000000 (0)
[junit4] 1> /solr/overseer_elect/election/90784425912565772-127.0.0.1:54595__%2Fi-n_0000000004 (0)
[junit4] 1> /solr/overseer_elect/leader (0)
[junit4] 1> DATA:
[junit4] 1> {"id":"90784425912565763-127.0.0.1:34416__%2Fi-n_0000000000"}
[junit4] 1> /zookeeper (1)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SyncSliceTest -Dtests.method=testDistribSearch -Dtests.seed=7A9509DF59666FB2 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_MX -Dtests.timezone=Asia/Kabul -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 131s J1 | SyncSliceTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: timeout waiting to see recovered node
[junit4] > at __randomizedtesting.SeedInfo.seed([7A9509DF59666FB2:FB7387C72E390F8E]:0)
[junit4] > at org.apache.solr.cloud.SyncSliceTest.waitTillRecovered(SyncSliceTest.java:265)
[junit4] > at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:188)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 1053518 T2712 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 131241 T2711 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4] 2> 1053530 T2787 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1054730 T2805 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene46: {range_facet_l=PostingsFormat(name=MockRandom), text=Lucene41(blocksize=128), _version_=PostingsFormat(name=Memory doPackFST= false), rnd_b=PostingsFormat(name=Asserting), intDefault=PostingsFormat(name=Memory doPackFST= false), timestamp=PostingsFormat(name=MockRandom), id=PostingsFormat(name=Asserting), a_t=PostingsFormat(name=MockRandom), range_facet_sl=PostingsFormat(name=Asserting), range_facet_si=PostingsFormat(name=MockRandom), other_tl1=PostingsFormat(name=Memory doPackFST= false), multiDefault=PostingsFormat(name=MockRandom), a_si=PostingsFormat(name=Memory doPackFST= false)}, docValues:{}, sim=DefaultSimilarity, locale=es_MX, timezone=Asia/Kabul
[junit4] 2> NOTE: Linux 3.8.0-33-generic i386/Oracle Corporation 1.7.0_45 (32-bit)/cpus=8,threads=6,free=125641776,total=302776320
[junit4] 2> NOTE: All tests run in this JVM: [OutputWriterTest, DocumentAnalysisRequestHandlerTest, TestWordDelimiterFilterFactory, SolrIndexConfigTest, MigrateRouteKeyTest, TestBinaryResponseWriter, TestStressLucene, TestRangeQuery, DocValuesMissingTest, NotRequiredUniqueKeyTest, TestBinaryField, TestLazyCores, DirectSolrSpellCheckerTest, HdfsCollectionsAPIDistributedZkTest, TestSolr4Spatial, SignatureUpdateProcessorFactoryTest, TestAtomicUpdateErrorCases, SpellCheckComponentTest, QueryResultKeyTest, AlternateDirectoryTest, DistributedSuggesterComponentTest, TestCSVResponseWriter, CollectionsAPIDistributedZkTest, ConvertedLegacyTest, TestSolrJ, TestSolrXml, ChangedSchemaMergeTest, TestQueryTypes, TestSchemaResource, TestDistributedGrouping, TestQuerySenderListener, TestSolrDeletionPolicy2, HighlighterConfigTest, AliasIntegrationTest, TestJmxIntegration, RequiredFieldsTest, SolrCmdDistributorTest, ChaosMonkeyNothingIsSafeTest, TestRandomMergePolicy, XsltUpdateRequestHandlerTest, InfoHandlerTest, TestSolrXmlPersistence, PreAnalyzedUpdateProcessorTest, DirectSolrConnectionTest, CurrencyFieldXmlFileTest, TestAddFieldRealTimeGet, TestCollapseQParserPlugin, TestStressRecovery, TestFileDictionaryLookup, OpenExchangeRatesOrgProviderTest, TestSchemaVersionResource, StatsComponentTest, TestSolrXmlPersistor, TestFieldTypeCollectionResource, TestCoreDiscovery, BasicDistributedZk2Test, SuggesterWFSTTest, TestCopyFieldCollectionResource, PathHierarchyTokenizerFactoryTest, SortByFunctionTest, BlockCacheTest, HardAutoCommitTest, TestFoldingMultitermQuery, TestOmitPositions, StandardRequestHandlerTest, TestSweetSpotSimilarityFactory, TestStressReorder, TestFuzzyAnalyzedSuggestions, RequestHandlersTest, DistanceFunctionTest, TestRandomFaceting, TestSchemaNameResource, BasicZkTest, SuggesterTSTTest, DocValuesMultiTest, SolrXmlInZkTest, PreAnalyzedFieldTest, TestPartialUpdateDeduplication, TestReloadAndDeleteDocs, SimplePostToolTest, TestUtils, ChaosMonkeySafeLeaderTest, TestSolrQueryParserDefaultOperatorResource, IndexSchemaRuntimeFieldTest, SpellingQueryConverterTest, SyncSliceTest]
[junit4] Completed on J1 in 132.52s, 1 test, 1 failure <<< FAILURES!
[...truncated 526 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:426: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:406: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:492: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1276: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:912: There were test failures: 345 suites, 1505 tests, 1 failure, 34 ignored (6 assumptions)
Total time: 55 minutes 18 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_45 -client -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure