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/08/19 13:11:10 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.7.0_25) - Build # 6993
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/6993/
Java: 64bit/jdk1.7.0_25 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.CustomCollectionTest.testDistribSearch
Error Message:
Not enough active replicas in the shard 'x'
Stack Trace:
java.lang.AssertionError: Not enough active replicas in the shard 'x'
at __randomizedtesting.SeedInfo.seed([CF3AA2123299A707:4EDC2C0A45C6C73B]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.CustomCollectionTest.testCustomCollectionsAPI(CustomCollectionTest.java:284)
at org.apache.solr.cloud.CustomCollectionTest.doTest(CustomCollectionTest.java:136)
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:724)
Build Log:
[...truncated 18528 lines...]
[junit4] Suite: org.apache.solr.cloud.CustomCollectionTest
[junit4] 2> 1615207 T3058 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 1615210 T3058 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-CustomCollectionTest-1376910361073
[junit4] 2> 1615211 T3058 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1615211 T3059 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1615311 T3058 oasc.ZkTestServer.run start zk server on port:39893
[junit4] 2> 1615313 T3058 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1615634 T3065 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14977c54 name:ZooKeeperConnection Watcher:127.0.0.1:39893 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1615634 T3058 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1615635 T3058 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1615840 T3058 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1616137 T3067 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@57e5d5e1 name:ZooKeeperConnection Watcher:127.0.0.1:39893/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1616138 T3058 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1616138 T3058 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1616349 T3058 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1616419 T3058 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1616505 T3058 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1616539 T3058 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 1616539 T3058 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1617267 T3058 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 1617268 T3058 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1617980 T3058 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 1617981 T3058 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1618029 T3058 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 1618029 T3058 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1618245 T3058 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 1618245 T3058 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1618298 T3058 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 1618299 T3058 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1618364 T3058 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 1618365 T3058 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1618492 T3058 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 1618492 T3058 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1618532 T3058 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 1618532 T3058 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1618670 T3058 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 1618671 T3058 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1618829 T3058 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1618833 T3058 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47391
[junit4] 2> 1618833 T3058 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1618833 T3058 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1618834 T3058 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CustomCollectionTest-controljetty-1376910364627
[junit4] 2> 1618834 T3058 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-controljetty-1376910364627/'
[junit4] 2> 1618843 T3058 oasc.ConfigSolr.fromFile Loading container configuration from /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1376910364627/solr.xml
[junit4] 2> 1618871 T3058 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 1618872 T3058 oasc.CoreContainer.<init> New CoreContainer 1776384827
[junit4] 2> 1618872 T3058 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CustomCollectionTest-controljetty-1376910364627/]
[junit4] 2> 1618873 T3058 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1618873 T3058 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1618873 T3058 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1618874 T3058 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1618874 T3058 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1618874 T3058 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1618874 T3058 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1618875 T3058 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1618875 T3058 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1618875 T3058 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1618877 T3058 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:39893/solr
[junit4] 2> 1618878 T3058 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1618879 T3058 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1618919 T3078 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@461b24c8 name:ZooKeeperConnection Watcher:127.0.0.1:39893 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1618920 T3058 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1618962 T3058 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1618966 T3058 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1619006 T3080 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@433a090b name:ZooKeeperConnection Watcher:127.0.0.1:39893/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1619006 T3058 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1619051 T3058 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1619175 T3058 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1619222 T3058 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1619262 T3058 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47391_
[junit4] 2> 1619295 T3058 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47391_
[junit4] 2> 1619342 T3058 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1619486 T3058 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1619531 T3058 oasc.Overseer.start Overseer (id=90237197423411203-127.0.0.1:47391_-n_0000000000) starting
[junit4] 2> 1619642 T3058 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1619707 T3082 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1619709 T3058 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1619752 T3058 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1619787 T3058 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1619792 T3081 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1619795 T3058 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1376910364627
[junit4] 2> 1619825 T3058 oasc.CorePropertiesLocator.discoverUnder Found core conf in /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1376910364627/conf/
[junit4] 2> 1619825 T3058 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 1619826 T3058 oass.SolrDispatchFilter.init user.dir=/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 1619826 T3058 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1619826 T3058 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1619828 T3058 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 1619829 T3058 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1619886 T3085 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@79ffe85 name:ZooKeeperConnection Watcher:127.0.0.1:39893/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1619887 T3058 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1619889 T3058 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1619892 T3058 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 1619962 T3058 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1619964 T3058 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36619
[junit4] 2> 1619964 T3058 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1619965 T3058 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1619965 T3058 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1376910365755
[junit4] 2> 1619965 T3058 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1376910365755/'
[junit4] 2> 1619974 T3058 oasc.ConfigSolr.fromFile Loading container configuration from /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1376910365755/solr.xml
[junit4] 2> 1620003 T3058 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 1620004 T3058 oasc.CoreContainer.<init> New CoreContainer 60792340
[junit4] 2> 1620004 T3058 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1376910365755/]
[junit4] 2> 1620005 T3058 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1620005 T3058 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1620005 T3058 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1620005 T3058 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1620006 T3058 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1620006 T3058 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1620006 T3058 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1620006 T3058 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1620007 T3058 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1620007 T3058 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1620009 T3058 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:39893/solr
[junit4] 2> 1620010 T3058 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1620010 T3058 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1620064 T3096 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@538b589b name:ZooKeeperConnection Watcher:127.0.0.1:39893 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1620064 T3058 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1620153 T3058 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1620158 T3058 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1620264 T3098 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@461839b1 name:ZooKeeperConnection Watcher:127.0.0.1:39893/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1620264 T3058 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1620409 T3058 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1621413 T3058 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36619_
[junit4] 2> 1621442 T3058 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36619_
[junit4] 2> 1621488 T3080 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1621488 T3098 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1621488 T3085 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1621524 T3058 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1376910365755
[junit4] 2> 1621566 T3058 oasc.CorePropertiesLocator.discoverUnder Found core conf in /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1376910365755/conf/
[junit4] 2> 1621567 T3058 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 1621567 T3058 oass.SolrDispatchFilter.init user.dir=/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 1621568 T3058 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1621568 T3058 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1621629 T3058 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1621631 T3058 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47034
[junit4] 2> 1621632 T3058 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1621633 T3058 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1621633 T3058 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1376910367432
[junit4] 2> 1621633 T3058 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1376910367432/'
[junit4] 2> 1621650 T3058 oasc.ConfigSolr.fromFile Loading container configuration from /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1376910367432/solr.xml
[junit4] 2> 1621685 T3058 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 1621685 T3058 oasc.CoreContainer.<init> New CoreContainer 1216393106
[junit4] 2> 1621686 T3058 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1376910367432/]
[junit4] 2> 1621687 T3058 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1621687 T3058 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1621687 T3058 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1621687 T3058 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1621687 T3058 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1621688 T3058 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1621688 T3058 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1621688 T3058 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1621688 T3058 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1621689 T3058 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1621691 T3058 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:39893/solr
[junit4] 2> 1621692 T3058 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1621693 T3058 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1621918 T3110 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63317852 name:ZooKeeperConnection Watcher:127.0.0.1:39893 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1621919 T3058 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1621953 T3058 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1621958 T3058 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1621995 T3112 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51669ce6 name:ZooKeeperConnection Watcher:127.0.0.1:39893/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1621996 T3058 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1622086 T3058 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1623090 T3058 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47034_
[junit4] 2> 1623184 T3058 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47034_
[junit4] 2> 1623231 T3098 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1623231 T3080 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1623231 T3085 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1623232 T3112 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1623278 T3058 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1376910367432
[junit4] 2> 1623313 T3058 oasc.CorePropertiesLocator.discoverUnder Found core conf in /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1376910367432/conf/
[junit4] 2> 1623313 T3058 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 1623314 T3058 oass.SolrDispatchFilter.init user.dir=/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 1623314 T3058 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1623314 T3058 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1623435 T3058 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1623437 T3058 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49918
[junit4] 2> 1623438 T3058 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1623438 T3058 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1623438 T3058 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1376910369179
[junit4] 2> 1623438 T3058 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1376910369179/'
[junit4] 2> 1623447 T3058 oasc.ConfigSolr.fromFile Loading container configuration from /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1376910369179/solr.xml
[junit4] 2> 1623491 T3058 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 1623492 T3058 oasc.CoreContainer.<init> New CoreContainer 1893733414
[junit4] 2> 1623492 T3058 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1376910369179/]
[junit4] 2> 1623493 T3058 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1623493 T3058 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1623494 T3058 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1623494 T3058 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1623494 T3058 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1623494 T3058 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1623494 T3058 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1623495 T3058 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1623495 T3058 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1623495 T3058 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1623498 T3058 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:39893/solr
[junit4] 2> 1623498 T3058 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1623499 T3058 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1623731 T3124 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@37eea41c name:ZooKeeperConnection Watcher:127.0.0.1:39893 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1623731 T3058 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1623775 T3058 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1623778 T3058 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1623817 T3126 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@34cfdb48 name:ZooKeeperConnection Watcher:127.0.0.1:39893/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1623818 T3058 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1623909 T3058 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1624913 T3058 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49918_
[junit4] 2> 1625578 T3058 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49918_
[junit4] 2> 1625641 T3112 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1625641 T3080 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1625641 T3098 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1625641 T3085 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1625641 T3126 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1625711 T3058 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1376910369179
[junit4] 2> 1625738 T3058 oasc.CorePropertiesLocator.discoverUnder Found core conf in /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1376910369179/conf/
[junit4] 2> 1625738 T3058 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 1625739 T3058 oass.SolrDispatchFilter.init user.dir=/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 1625739 T3058 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1625740 T3058 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1625801 T3058 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1625803 T3058 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:42201
[junit4] 2> 1625804 T3058 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1625804 T3058 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1625804 T3058 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604
[junit4] 2> 1625805 T3058 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/'
[junit4] 2> 1625813 T3058 oasc.ConfigSolr.fromFile Loading container configuration from /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/solr.xml
[junit4] 2> 1625841 T3058 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 1625841 T3058 oasc.CoreContainer.<init> New CoreContainer 381328654
[junit4] 2> 1625841 T3058 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/]
[junit4] 2> 1625842 T3058 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1625842 T3058 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1625843 T3058 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1625843 T3058 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1625843 T3058 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1625843 T3058 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1625843 T3058 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1625844 T3058 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1625844 T3058 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1625844 T3058 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1625847 T3058 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:39893/solr
[junit4] 2> 1625847 T3058 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1625847 T3058 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1625884 T3138 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3be31c26 name:ZooKeeperConnection Watcher:127.0.0.1:39893 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1625884 T3058 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1625965 T3058 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1625970 T3058 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1626195 T3140 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@21ad62ed name:ZooKeeperConnection Watcher:127.0.0.1:39893/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1626195 T3058 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1626365 T3058 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1627371 T3058 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42201_
[junit4] 2> 1627419 T3058 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42201_
[junit4] 2> 1627474 T3112 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1627474 T3080 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1627474 T3098 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1627474 T3085 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1627474 T3126 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1627474 T3140 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1627546 T3058 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604
[junit4] 2> 1627576 T3058 oasc.CorePropertiesLocator.discoverUnder Found core conf in /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/conf/
[junit4] 2> 1627576 T3058 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 1627576 T3058 oass.SolrDispatchFilter.init user.dir=/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 1627577 T3058 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1627577 T3058 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1627579 T3058 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 1627580 T3058 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1627617 T3143 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@250a4f92 name:ZooKeeperConnection Watcher:127.0.0.1:39893/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1627617 T3058 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1627620 T3058 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1627623 T3058 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 1627625 T3058 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1627661 T3145 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7e7d37a6 name:ZooKeeperConnection Watcher:127.0.0.1:39893/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1627662 T3058 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1627664 T3058 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1627673 T3133 oasha.CollectionsHandler.handleCreateAction Creating Collection : shards=a,b,c&maxShardsPerNode=2&router=implicit&name=implicitcoll0&replicationFactor=2&action=CREATE&wt=javabin&version=2
[junit4] 2> 1627708 T3080 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1627784 T3082 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
[junit4] 2> "operation":"createcollection",
[junit4] 2> "shards":"a,b,c",
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "router":"implicit",
[junit4] 2> "name":"implicitcoll0",
[junit4] 2> "replicationFactor":"2"}
[junit4] 2> 1627785 T3082 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
[junit4] 2> "operation":"createcollection",
[junit4] 2> "shards":"a,b,c",
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "router":"implicit",
[junit4] 2> "name":"implicitcoll0",
[junit4] 2> "replicationFactor":"2"}
[junit4] 2> 1628807 T3081 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1628807 T3081 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: implicitcoll0
[junit4] 2> 1628808 T3081 oasc.Overseer$ClusterStateUpdater.createCollection Create collection implicitcoll0 with shards [a, b, c]
[junit4] 2> 1629818 T3062 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 1009ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
[junit4] 2> 1630119 T3112 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> 1630119 T3098 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> 1630119 T3080 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> 1630119 T3126 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> 1630119 T3140 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> 1630119 T3085 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> 1630120 T3145 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> 1630119 T3143 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> 1630226 T3082 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [a, b, c] , repFactor : 2
[junit4] 2> 1630227 T3082 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_a_replica1 as part of slice a of collection implicitcoll0 on 127.0.0.1:42201_
[junit4] 2> 1630227 T3082 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_a_replica2 as part of slice a of collection implicitcoll0 on 127.0.0.1:47391_
[junit4] 2> 1630228 T3082 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_b_replica1 as part of slice b of collection implicitcoll0 on 127.0.0.1:36619_
[junit4] 2> 1630229 T3082 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_b_replica2 as part of slice b of collection implicitcoll0 on 127.0.0.1:47034_
[junit4] 2> 1630230 T3082 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_c_replica1 as part of slice c of collection implicitcoll0 on 127.0.0.1:49918_
[junit4] 2> 1630231 T3082 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_c_replica2 as part of slice c of collection implicitcoll0 on 127.0.0.1:42201_
[junit4] 2> 1630232 T3134 oasc.ZkController.publish publishing core=implicitcoll0_a_replica1 state=down
[junit4] 2> 1630232 T3094 oasc.ZkController.publish publishing core=implicitcoll0_b_replica1 state=down
[junit4] 2> 1630232 T3073 oasc.ZkController.publish publishing core=implicitcoll0_a_replica2 state=down
[junit4] 2> 1630233 T3135 oasc.ZkController.publish publishing core=implicitcoll0_c_replica2 state=down
[junit4] 2> 1630232 T3107 oasc.ZkController.publish publishing core=implicitcoll0_b_replica2 state=down
[junit4] 2> 1630233 T3122 oasc.ZkController.publish publishing core=implicitcoll0_c_replica1 state=down
[junit4] 2> 1630264 T3134 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1630446 T3094 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1630446 T3122 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1630446 T3107 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1630446 T3135 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1630446 T3073 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1631665 T3081 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1631667 T3081 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"3",
[junit4] 2> "shard":"a",
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"implicitcoll0_a_replica1",
[junit4] 2> "collection":"implicitcoll0",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:42201_",
[junit4] 2> "base_url":"http://127.0.0.1:42201"}
[junit4] 2> 1631830 T3081 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "numShards":"3",
[junit4] 2> "shard":"b",
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"implicitcoll0_b_replica1",
[junit4] 2> "collection":"implicitcoll0",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:36619_",
[junit4] 2> "base_url":"http://127.0.0.1:36619"}
[junit4] 2> 1631896 T3081 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "numShards":"3",
[junit4] 2> "shard":"a",
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"implicitcoll0_a_replica2",
[junit4] 2> "collection":"implicitcoll0",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:47391_",
[junit4] 2> "base_url":"http://127.0.0.1:47391"}
[junit4] 2> 1631984 T3081 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "numShards":"3",
[junit4] 2> "shard":"c",
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"implicitcoll0_c_replica2",
[junit4] 2> "collection":"implicitcoll0",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:42201_",
[junit4] 2> "base_url":"http://127.0.0.1:42201"}
[junit4] 2> 1632124 T3081 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node5",
[junit4] 2> "numShards":"3",
[junit4] 2> "shard":"b",
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"implicitcoll0_b_replica2",
[junit4] 2> "collection":"implicitcoll0",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:47034_",
[junit4] 2> "base_url":"http://127.0.0.1:47034"}
[junit4] 2> 1632364 T3081 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node6",
[junit4] 2> "numShards":"3",
[junit4] 2> "shard":"c",
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"implicitcoll0_c_replica1",
[junit4] 2> "collection":"implicitcoll0",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:49918_",
[junit4] 2> "base_url":"http://127.0.0.1:49918"}
[junit4] 2> 1632441 T3080 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> 1632442 T3143 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> 1632442 T3085 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> 1632442 T3145 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> 1632442 T3126 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> 1632442 T3140 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> 1632441 T3112 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> 1632442 T3098 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> 1632447 T3122 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_c_replica1
[junit4] 2> 1632448 T3122 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_c_replica1' using instanceDir: ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1376910369179/implicitcoll0_c_replica1
[junit4] 2> 1632448 T3122 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
[junit4] 2> 1632464 T3122 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
[junit4] 2> 1632464 T3122 oasc.ZkController.getConfName Looking for collection configName
[junit4] 2> 1632486 T3122 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4] 2> 1632487 T3122 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
[junit4] 2> 1632553 T3122 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
[junit4] 2> 1632575 T3122 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1376910369179/implicitcoll0_c_replica1/'
[junit4] 2> 1632627 T3122 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 1632656 T3122 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1632657 T3122 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1632663 T3122 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 1632965 T3122 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1632965 T3122 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1632966 T3122 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1632970 T3122 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1632973 T3122 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1632986 T3122 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1632989 T3122 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1632992 T3122 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1632994 T3122 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1632994 T3122 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1632994 T3122 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1632995 T3122 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1632995 T3122 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1632996 T3122 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1632996 T3122 oasc.SolrCore.<init> [implicitcoll0_c_replica1] Opening new SolrCore at ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1376910369179/implicitcoll0_c_replica1/, dataDir=../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1376910369179/implicitcoll0_c_replica1/data/
[junit4] 2> 1632996 T3122 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@72f49e0e
[junit4] 2> 1632997 T3122 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1376910369179/implicitcoll0_c_replica1/data
[junit4] 2> 1632997 T3122 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1376910369179/implicitcoll0_c_replica1/data/index/
[junit4] 2> 1632997 T3122 oasc.SolrCore.initIndex WARN [implicitcoll0_c_replica1] Solr index directory '../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1376910369179/implicitcoll0_c_replica1/data/index' doesn't exist. Creating new index...
[junit4] 2> 1632998 T3122 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1376910369179/implicitcoll0_c_replica1/data/index
[junit4] 2> 1632998 T3122 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=41, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1632999 T3122 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2210049 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@ff51826),segFN=segments_1,generation=1}
[junit4] 2> 1632999 T3122 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1633001 T3122 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1633001 T3122 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1633002 T3122 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1633002 T3122 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1633002 T3122 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1633002 T3122 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1633003 T3122 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1633003 T3122 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1633003 T3122 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1633004 T3122 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1633004 T3122 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1633004 T3122 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1633004 T3122 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1633005 T3122 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1633005 T3122 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1633008 T3122 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1633011 T3122 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1633011 T3122 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1633012 T3122 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=16, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.801341837697972]
[junit4] 2> 1633013 T3122 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2210049 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@ff51826),segFN=segments_1,generation=1}
[junit4] 2> 1633013 T3122 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1633013 T3122 oass.SolrIndexSearcher.<init> Opening Searcher@fefb32a main
[junit4] 2> 1633016 T3152 oasc.SolrCore.registerSearcher [implicitcoll0_c_replica1] Registered new searcher Searcher@fefb32a main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1633017 T3122 oasc.CoreContainer.registerCore registering core: implicitcoll0_c_replica1
[junit4] 2> 1633017 T3122 oasc.ZkController.register Register replica - core:implicitcoll0_c_replica1 address:http://127.0.0.1:49918 collection:implicitcoll0 shard:c
[junit4] 2> 1633017 T3122 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 1633020 T3122 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0/leader_elect/c/election
[junit4] 2> 1633265 T3134 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_a_replica1
[junit4] 2> 1633266 T3134 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_a_replica1' using instanceDir: ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/implicitcoll0_a_replica1
[junit4] 2> 1633266 T3134 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
[junit4] 2> 1633447 T3094 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_b_replica1
[junit4] 2> 1633448 T3107 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_b_replica2
[junit4] 2> 1633448 T3094 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_b_replica1' using instanceDir: ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1376910365755/implicitcoll0_b_replica1
[junit4] 2> 1633448 T3135 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_c_replica2
[junit4] 2> 1633448 T3107 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_b_replica2' using instanceDir: ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1376910367432/implicitcoll0_b_replica2
[junit4] 2> 1633449 T3107 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
[junit4] 2> 1633448 T3094 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
[junit4] 2> 1633449 T3135 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_c_replica2' using instanceDir: ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/implicitcoll0_c_replica2
[junit4] 2> 1633448 T3073 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_a_replica2
[junit4] 2> 1633450 T3135 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
[junit4] 2> 1633450 T3073 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_a_replica2' using instanceDir: ./org.apache.solr.cloud.CustomCollectionTest-controljetty-1376910364627/implicitcoll0_a_replica2
[junit4] 2> 1633450 T3073 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
[junit4] 2> 1633782 T3134 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1633783 T3134 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
[junit4] 2> 1633783 T3073 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1633783 T3135 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1633784 T3135 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
[junit4] 2> 1633782 T3094 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1633785 T3094 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
[junit4] 2> 1633782 T3107 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1633785 T3107 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
[junit4] 2> 1633783 T3073 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
[junit4] 2> 1634062 T3094 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1376910365755/implicitcoll0_b_replica1/'
[junit4] 2> 1634062 T3073 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-controljetty-1376910364627/implicitcoll0_a_replica2/'
[junit4] 2> 1634062 T3107 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1376910367432/implicitcoll0_b_replica2/'
[junit4] 2> 1634062 T3135 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/implicitcoll0_c_replica2/'
[junit4] 2> 1634062 T3134 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/implicitcoll0_a_replica1/'
[junit4] 2> 1634243 T3094 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 1634246 T3135 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 1634248 T3134 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 1634251 T3107 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 1634254 T3073 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 1634275 T3122 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard c
[junit4] 2> 1634275 T3094 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1634280 T3134 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1634289 T3107 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1634295 T3135 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1634303 T3073 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1634353 T3134 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1634353 T3094 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1634353 T3107 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1634353 T3073 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1634353 T3135 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1634359 T3073 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 1634362 T3134 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 1634362 T3135 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 1634362 T3107 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 1634362 T3094 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 1634420 T3122 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard c: total=2 found=1 timeoutin=179999
[junit4] 2> 1634796 T3135 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1634796 T3135 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1634797 T3135 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1634802 T3135 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1634804 T3135 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1634814 T3135 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1634817 T3135 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1634820 T3135 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1634821 T3135 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1634822 T3135 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1634822 T3135 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1634823 T3135 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1634824 T3135 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1634824 T3135 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1634824 T3135 oasc.SolrCore.<init> [implicitcoll0_c_replica2] Opening new SolrCore at ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/implicitcoll0_c_replica2/, dataDir=../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/implicitcoll0_c_replica2/data/
[junit4] 2> 1634824 T3135 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@72f49e0e
[junit4] 2> 1634825 T3135 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/implicitcoll0_c_replica2/data
[junit4] 2> 1634825 T3135 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/implicitcoll0_c_replica2/data/index/
[junit4] 2> 1634826 T3135 oasc.SolrCore.initIndex WARN [implicitcoll0_c_replica2] Solr index directory '../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/implicitcoll0_c_replica2/data/index' doesn't exist. Creating new index...
[junit4] 2> 1634826 T3135 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/implicitcoll0_c_replica2/data/index
[junit4] 2> 1634826 T3073 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1634826 T3135 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=41, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1634827 T3073 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1634827 T3135 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6cc0adcc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3318f299),segFN=segments_1,generation=1}
[junit4] 2> 1634828 T3135 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1634828 T3073 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1634830 T3135 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1634831 T3135 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1634831 T3135 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1634831 T3135 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1634831 T3135 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1634832 T3135 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1634832 T3135 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1634832 T3134 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1634832 T3135 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1634833 T3135 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1634833 T3134 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1634833 T3135 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1634834 T3107 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1634834 T3134 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1634834 T3107 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1634834 T3135 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1634835 T3135 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1634835 T3135 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1634835 T3107 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1634835 T3135 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1634835 T3073 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1634836 T3135 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1634843 T3135 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1634846 T3135 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1634846 T3073 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1634846 T3135 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1634847 T3135 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=16, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.801341837697972]
[junit4] 2> 1634847 T3134 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1634848 T3135 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6cc0adcc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3318f299),segFN=segments_1,generation=1}
[junit4] 2> 1634848 T3135 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1634848 T3135 oass.SolrIndexSearcher.<init> Opening Searcher@3da59750 main
[junit4] 2> 1634849 T3107 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1634851 T3154 oasc.SolrCore.registerSearcher [implicitcoll0_c_replica2] Registered new searcher Searcher@3da59750 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1634851 T3134 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1634852 T3135 oasc.CoreContainer.registerCore registering core: implicitcoll0_c_replica2
[junit4] 2> 1634852 T3135 oasc.ZkController.register Register replica - core:implicitcoll0_c_replica2 address:http://127.0.0.1:42201 collection:implicitcoll0 shard:c
[junit4] 2> 1634853 T3135 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 1634853 T3107 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1634853 T3094 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1634854 T3094 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1634856 T3094 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1634861 T3094 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1634863 T3094 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1635002 T3122 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1635003 T3122 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1635003 T3122 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49918/implicitcoll0_c_replica1/
[junit4] 2> 1635004 T3122 oasu.PeerSync.sync PeerSync: core=implicitcoll0_c_replica1 url=http://127.0.0.1:49918 START replicas=[http://127.0.0.1:42201/implicitcoll0_c_replica2/] nUpdates=100
[junit4] 2> 1635004 T3122 oasu.PeerSync.sync PeerSync: core=implicitcoll0_c_replica1 url=http://127.0.0.1:49918 DONE. We have no versions. sync failed.
[junit4] 2> 1635004 T3122 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 1635005 T3122 oasc.ShardLeaderElectionContext.runLeaderProcess We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 1635005 T3122 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49918/implicitcoll0_c_replica1/ c
[junit4] 2> 1635006 T3122 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0/leaders/c
[junit4] 2> ASYNC NEW_CORE C3600 name=implicitcoll0_c_replica2 org.apache.solr.core.SolrCore@3f2764a url=http://127.0.0.1:42201/implicitcoll0_c_replica2 node=127.0.0.1:42201_ C3600_STATE=coll:implicitcoll0 core:implicitcoll0_c_replica2 props:{state=down, core=implicitcoll0_c_replica2, node_name=127.0.0.1:42201_, base_url=http://127.0.0.1:42201}
[junit4] 2> 1635013 T3136 C3600 P42201 oasc.SolrCore.execute [implicitcoll0_c_replica2] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=3
[junit4] 2> 1635198 T3073 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1635276 T3073 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1635334 T3134 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1635335 T3073 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1635337 T3107 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1635337 T3094 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1635337 T3073 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1635339 T3073 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1635339 T3073 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1635340 T3134 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1635340 T3073 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1635341 T3073 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1635341 T3073 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1635341 T3073 oasc.SolrCore.<init> [implicitcoll0_a_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CustomCollectionTest-controljetty-1376910364627/implicitcoll0_a_replica2/, dataDir=./org.apache.solr.cloud.CustomCollectionTest-controljetty-1376910364627/implicitcoll0_a_replica2/data/
[junit4] 2> 1635341 T3073 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@72f49e0e
[junit4] 2> 1635342 T3107 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1635342 T3134 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1635342 T3073 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CustomCollectionTest-controljetty-1376910364627/implicitcoll0_a_replica2/data
[junit4] 2> 1635342 T3094 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1635343 T3073 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CustomCollectionTest-controljetty-1376910364627/implicitcoll0_a_replica2/data/index/
[junit4] 2> 1635343 T3073 oasc.SolrCore.initIndex WARN [implicitcoll0_a_replica2] Solr index directory './org.apache.solr.cloud.CustomCollectionTest-controljetty-1376910364627/implicitcoll0_a_replica2/data/index' doesn't exist. Creating new index...
[junit4] 2> 1635344 T3073 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CustomCollectionTest-controljetty-1376910364627/implicitcoll0_a_replica2/data/index
[junit4] 2> 1635344 T3134 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1635344 T3073 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=41, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1635345 T3134 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1635345 T3134 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1635345 T3073 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@348d1a69 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@421e2b82),segFN=segments_1,generation=1}
[junit4] 2> 1635346 T3073 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1635346 T3107 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1635346 T3094 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1635347 T3134 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1635348 T3134 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4
[...truncated too long message...]
r-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/implicitcoll0_a_replica1/data
[junit4] 2> 1713288 T3058 oasc.SolrCore.close [implicitcoll1_b_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@489a11b4
[junit4] 2> 1713292 T3058 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=4,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=1,cumulative_errors=0}
[junit4] 2> 1713293 T3058 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 1713293 T3058 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1713293 T3058 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 1713294 T3058 oasc.SolrCore.closeSearcher [implicitcoll1_b_replica1] Closing main searcher on request.
[junit4] 2> 1713294 T3058 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1713294 T3058 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/implicitcoll1_b_replica1/data/index [CachedDir<<refCount=0;path=../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/implicitcoll1_b_replica1/data/index;done=false>>]
[junit4] 2> 1713294 T3058 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/implicitcoll1_b_replica1/data/index
[junit4] 2> 1713295 T3058 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/implicitcoll1_b_replica1/data [CachedDir<<refCount=0;path=../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/implicitcoll1_b_replica1/data;done=false>>]
[junit4] 2> 1713295 T3058 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1376910371604/implicitcoll1_b_replica1/data
[junit4] 2> 1713296 T3218 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90237197423411212-127.0.0.1:42201_-n_0000000004) am no longer a leader.
[junit4] 2> 1713376 T3058 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4] 2> 1713428 T3058 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 1713430 T3058 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:39893 39893
[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=CF3AA2123299A707 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=sv -Dtests.timezone=Europe/Amsterdam -Dtests.file.encoding=UTF-8
[junit4] FAILURE 98.6s J1 | CustomCollectionTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: Not enough active replicas in the shard 'x'
[junit4] > at __randomizedtesting.SeedInfo.seed([CF3AA2123299A707:4EDC2C0A45C6C73B]:0)
[junit4] > at org.apache.solr.cloud.CustomCollectionTest.testCustomCollectionsAPI(CustomCollectionTest.java:284)
[junit4] > at org.apache.solr.cloud.CustomCollectionTest.doTest(CustomCollectionTest.java:136)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] 2> 1713822 T3058 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 98619 T3057 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4] 2> 1714654 T3140 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1714654 T3140 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1714654 T3140 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene42: {_route_=PostingsFormat(name=MockRandom), range_facet_l=PostingsFormat(name=Direct), text=PostingsFormat(name=MockRandom), _version_=PostingsFormat(name=Direct), intDefault=PostingsFormat(name=Direct), timestamp=PostingsFormat(name=Direct), id=PostingsFormat(name=MockSep), a_t=PostingsFormat(name=Direct), range_facet_sl=PostingsFormat(name=MockRandom), range_facet_si=Pulsing41(freqCutoff=2 minBlockSize=96 maxBlockSize=251), other_tl1=PostingsFormat(name=Direct), multiDefault=Pulsing41(freqCutoff=2 minBlockSize=96 maxBlockSize=251), a_si=Pulsing41(freqCutoff=2 minBlockSize=96 maxBlockSize=251)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=sv, timezone=Europe/Amsterdam
[junit4] 2> NOTE: Linux 3.2.0-51-generic amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=8,threads=1,free=112826296,total=366870528
[junit4] 2> NOTE: All tests run in this JVM: [TestCollationKeyRangeQueries, ZkSolrClientTest, TestIndexingPerformance, TestSolrJ, LeaderElectionIntegrationTest, CachingDirectoryFactoryTest, SuggesterWFSTTest, ChaosMonkeyNothingIsSafeTest, TestArbitraryIndexDir, BlockCacheTest, DirectSolrConnectionTest, HdfsSyncSliceTest, TestDFRSimilarityFactory, TestSchemaResource, TestBinaryField, TestInfoStreamLogging, TestAnalyzedSuggestions, TestCollationField, TestQueryTypes, TestAtomicUpdateErrorCases, TestUtils, TestCoreDiscovery, TestQuerySenderNoQuery, MinimalSchemaTest, HdfsBasicDistributedZkTest, PreAnalyzedUpdateProcessorTest, HighlighterTest, OpenCloseCoreStressTest, StatsComponentTest, TestLazyCores, TestSchemaVersionResource, TestHashPartitioner, SolrXmlInZkTest, AlternateDirectoryTest, CoreAdminCreateDiscoverTest, StandardRequestHandlerTest, TestFieldCollectionResource, TestPhraseSuggestions, TestZkChroot, TestComponentsName, TestIndexSearcher, TestRecovery, DefaultValueUpdateProcessorTest, SolrRequestParserTest, DisMaxRequestHandlerTest, TestWordDelimiterFilterFactory, DirectSolrSpellCheckerTest, NoCacheHeaderTest, TestSolr4Spatial, CurrencyFieldXmlFileTest, HardAutoCommitTest, QueryResultKeyTest, SpellingQueryConverterTest, HdfsChaosMonkeySafeLeaderTest, TestXIncludeConfig, TestUpdate, PreAnalyzedFieldTest, TestDefaultSimilarityFactory, TestRangeQuery, TestFastOutputStream, TermVectorComponentDistributedTest, TestSweetSpotSimilarityFactory, DistanceFunctionTest, SpellCheckComponentTest, TestDynamicFieldCollectionResource, JSONWriterTest, TestIBSimilarityFactory, TestFoldingMultitermQuery, RequiredFieldsTest, DirectUpdateHandlerTest, CoreContainerCoreInitFailuresTest, SimplePostToolTest, AddBlockUpdateTest, TestDistributedGrouping, BasicZkTest, TestFastWriter, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, CollectionsAPIDistributedZkTest, TestRandomFaceting, ShardRoutingCustomTest, TestDistributedSearch, TestRealTimeGet, TestJoin, SimpleFacetsTest, TestGroupingSearch, ConvertedLegacyTest, TestFunctionQuery, CurrencyFieldOpenExchangeTest, SolrIndexSplitterTest, SignatureUpdateProcessorFactoryTest, CoreAdminHandlerTest, DocValuesTest, SuggesterTSTTest, TestStressLucene, WordBreakSolrSpellCheckerTest, DirectUpdateHandlerOptimizeTest, DocValuesMultiTest, XsltUpdateRequestHandlerTest, IndexBasedSpellCheckerTest, TestQueryUtils, DocumentAnalysisRequestHandlerTest, TermsComponentTest, RequestHandlersTest, TestValueSourceCache, TermVectorComponentTest, FieldAnalysisRequestHandlerTest, RegexBoostProcessorTest, TestJmxIntegration, QueryParsingTest, UniqFieldsUpdateProcessorFactoryTest, BinaryUpdateRequestHandlerTest, PingRequestHandlerTest, TestLFUCache, SOLR749Test, UpdateParamsTest, ResponseLogComponentTest, SolrIndexConfigTest, TestStressRecovery, AssignTest, CustomCollectionTest]
[junit4] Completed on J1 in 99.65s, 1 test, 1 failure <<< FAILURES!
[...truncated 98 lines...]
BUILD FAILED
/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:395: The following error occurred while executing this line:
/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:375: The following error occurred while executing this line:
/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:181: The following error occurred while executing this line:
/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:450: The following error occurred while executing this line:
/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1233: The following error occurred while executing this line:
/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:876: There were test failures: 323 suites, 1376 tests, 1 failure, 34 ignored (6 assumptions)
Total time: 50 minutes 54 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_25 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure