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/05/31 16:10:37 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.6.0_45) - Build # 5854
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/5854/
Java: 32bit/jdk1.6.0_45 -server -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
Error Message:
There are still nodes recoverying - waited for 230 seconds
Stack Trace:
java.lang.AssertionError: There are still nodes recoverying - waited for 230 seconds
at __randomizedtesting.SeedInfo.seed([BA96622C23C1655C:3B70EC34549E0560]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:173)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:126)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:512)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:146)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:662)
Build Log:
[...truncated 9127 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4:junit4] 2> 604456 T2632 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /je/mw
[junit4:junit4] 2> 604459 T2632 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1370008658877
[junit4:junit4] 2> 604460 T2632 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 604460 T2633 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 604560 T2632 oasc.ZkTestServer.run start zk server on port:52762
[junit4:junit4] 2> 604561 T2632 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 604659 T2639 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@635922 name:ZooKeeperConnection Watcher:127.0.0.1:52762 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 604659 T2632 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 604660 T2632 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 604665 T2632 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 604666 T2641 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d340b5 name:ZooKeeperConnection Watcher:127.0.0.1:52762/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 604666 T2632 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 604666 T2632 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 604669 T2632 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 604671 T2632 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 604672 T2632 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 604674 T2632 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 604674 T2632 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 604678 T2632 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 604678 T2632 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 604681 T2632 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 604681 T2632 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 604683 T2632 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 604683 T2632 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 604685 T2632 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 604686 T2632 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 604688 T2632 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 604688 T2632 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 604690 T2632 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 604690 T2632 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 604693 T2632 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 604693 T2632 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 604695 T2632 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 604695 T2632 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 604763 T2632 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 604765 T2632 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:60580
[junit4:junit4] 2> 604765 T2632 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 604766 T2632 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 604766 T2632 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116
[junit4:junit4] 2> 604766 T2632 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/solr.xml
[junit4:junit4] 2> 604767 T2632 oasc.CoreContainer.<init> New CoreContainer 32292731
[junit4:junit4] 2> 604767 T2632 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/'
[junit4:junit4] 2> 604767 T2632 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/'
[junit4:junit4] 2> 604812 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116
[junit4:junit4] 2> 604813 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/collection1
[junit4:junit4] 2> 604814 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/collection1/conf
[junit4:junit4] 2> 604818 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/collection1/conf/xslt
[junit4:junit4] 2> 604835 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/collection1/lib
[junit4:junit4] 2> 604835 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/collection1/lib/classes
[junit4:junit4] 2> 604837 T2632 oasc.SolrCoreDiscoverer.addCore Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/conf/core.properties, adding to cores
[junit4:junit4] 2> 604839 T2632 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 604839 T2632 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 604839 T2632 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 604840 T2632 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 604840 T2632 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 604840 T2632 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 604841 T2632 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 604841 T2632 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 604841 T2632 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 604842 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 604845 T2632 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 604845 T2632 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52762/solr
[junit4:junit4] 2> 604846 T2632 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 604846 T2632 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 604848 T2652 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@85c7d9 name:ZooKeeperConnection Watcher:127.0.0.1:52762 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 604848 T2632 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 604850 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 604853 T2632 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 604854 T2654 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@60bdf7 name:ZooKeeperConnection Watcher:127.0.0.1:52762/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 604855 T2632 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 604856 T2632 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 604859 T2632 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 604861 T2632 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 604862 T2632 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60580_je%2Fmw
[junit4:junit4] 2> 604863 T2632 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60580_je%2Fmw
[junit4:junit4] 2> 604864 T2632 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 604869 T2632 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 604871 T2632 oasc.Overseer.start Overseer (id=89784887468294147-127.0.0.1:60580_je%2Fmw-n_0000000000) starting
[junit4:junit4] 2> 604873 T2632 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 604876 T2656 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 604876 T2632 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 604878 T2632 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 604879 T2632 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 604881 T2655 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 604882 T2632 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 604882 T2632 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 604883 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 604885 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 604886 T2632 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 604887 T2659 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f4edd5 name:ZooKeeperConnection Watcher:127.0.0.1:52762/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 604887 T2632 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 604889 T2632 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 604890 T2632 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 604955 T2632 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 604957 T2632 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:42496
[junit4:junit4] 2> 604957 T2632 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 604957 T2632 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 604958 T2632 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308
[junit4:junit4] 2> 604958 T2632 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/solr.xml
[junit4:junit4] 2> 604958 T2632 oasc.CoreContainer.<init> New CoreContainer 2726648
[junit4:junit4] 2> 604959 T2632 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/'
[junit4:junit4] 2> 604959 T2632 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/'
[junit4:junit4] 2> 604999 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308
[junit4:junit4] 2> 605000 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/collection1
[junit4:junit4] 2> 605000 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/collection1/conf
[junit4:junit4] 2> 605005 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/collection1/conf/xslt
[junit4:junit4] 2> 605021 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/collection1/lib
[junit4:junit4] 2> 605022 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/collection1/lib/classes
[junit4:junit4] 2> 605023 T2632 oasc.SolrCoreDiscoverer.addCore Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/conf/core.properties, adding to cores
[junit4:junit4] 2> 605025 T2632 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 605026 T2632 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 605026 T2632 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 605026 T2632 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 605026 T2632 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 605027 T2632 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 605027 T2632 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 605027 T2632 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 605028 T2632 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 605028 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 605031 T2632 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 605031 T2632 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52762/solr
[junit4:junit4] 2> 605032 T2632 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 605033 T2632 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 605034 T2670 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f9dfc2 name:ZooKeeperConnection Watcher:127.0.0.1:52762 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 605034 T2632 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 605035 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 605038 T2632 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 605039 T2672 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e58a3 name:ZooKeeperConnection Watcher:127.0.0.1:52762/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 605040 T2632 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 605043 T2632 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 606045 T2632 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42496_je%2Fmw
[junit4:junit4] 2> 606046 T2632 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42496_je%2Fmw
[junit4:junit4] 2> 606049 T2659 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 606049 T2672 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 606049 T2654 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 606053 T2632 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 606053 T2632 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 606053 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 606120 T2632 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 606121 T2632 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44782
[junit4:junit4] 2> 606122 T2632 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 606122 T2632 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 606123 T2632 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473
[junit4:junit4] 2> 606123 T2632 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/solr.xml
[junit4:junit4] 2> 606123 T2632 oasc.CoreContainer.<init> New CoreContainer 28207971
[junit4:junit4] 2> 606124 T2632 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/'
[junit4:junit4] 2> 606124 T2632 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/'
[junit4:junit4] 2> 606164 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473
[junit4:junit4] 2> 606165 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/collection1
[junit4:junit4] 2> 606165 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/collection1/conf
[junit4:junit4] 2> 606170 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/collection1/conf/xslt
[junit4:junit4] 2> 606194 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/collection1/lib
[junit4:junit4] 2> 606194 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/collection1/lib/classes
[junit4:junit4] 2> 606196 T2632 oasc.SolrCoreDiscoverer.addCore Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/conf/core.properties, adding to cores
[junit4:junit4] 2> 606198 T2632 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 606198 T2632 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 606198 T2632 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 606199 T2632 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 606199 T2632 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 606199 T2632 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 606200 T2632 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 606200 T2632 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 606200 T2632 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 606201 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 606203 T2632 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 606204 T2632 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52762/solr
[junit4:junit4] 2> 606204 T2632 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 606205 T2632 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 606206 T2684 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1309a65 name:ZooKeeperConnection Watcher:127.0.0.1:52762 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 606207 T2632 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 606208 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 606211 T2632 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 606213 T2686 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@192dc3d name:ZooKeeperConnection Watcher:127.0.0.1:52762/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 606213 T2632 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 606216 T2632 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 607219 T2632 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44782_je%2Fmw
[junit4:junit4] 2> 607220 T2632 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44782_je%2Fmw
[junit4:junit4] 2> 607223 T2654 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 607223 T2686 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 607224 T2659 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 607223 T2672 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 607228 T2632 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 607228 T2632 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 607229 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 607319 T2632 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 607321 T2632 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:35800
[junit4:junit4] 2> 607321 T2632 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 607322 T2632 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 607322 T2632 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650
[junit4:junit4] 2> 607322 T2632 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/solr.xml
[junit4:junit4] 2> 607323 T2632 oasc.CoreContainer.<init> New CoreContainer 3933495
[junit4:junit4] 2> 607323 T2632 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/'
[junit4:junit4] 2> 607323 T2632 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/'
[junit4:junit4] 2> 607365 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650
[junit4:junit4] 2> 607366 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/collection1
[junit4:junit4] 2> 607367 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/collection1/conf
[junit4:junit4] 2> 607371 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/collection1/conf/xslt
[junit4:junit4] 2> 607388 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/collection1/lib
[junit4:junit4] 2> 607389 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/collection1/lib/classes
[junit4:junit4] 2> 607390 T2632 oasc.SolrCoreDiscoverer.addCore Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/conf/core.properties, adding to cores
[junit4:junit4] 2> 607392 T2632 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 607392 T2632 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 607393 T2632 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 607393 T2632 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 607393 T2632 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 607393 T2632 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 607394 T2632 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 607394 T2632 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 607394 T2632 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 607395 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 607398 T2632 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 607398 T2632 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52762/solr
[junit4:junit4] 2> 607398 T2632 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 607399 T2632 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 607401 T2698 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e6d29e name:ZooKeeperConnection Watcher:127.0.0.1:52762 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 607401 T2632 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 607402 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 607405 T2632 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 607406 T2700 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e25c07 name:ZooKeeperConnection Watcher:127.0.0.1:52762/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 607407 T2632 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 607410 T2632 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 608412 T2632 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35800_je%2Fmw
[junit4:junit4] 2> 608414 T2632 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35800_je%2Fmw
[junit4:junit4] 2> 608416 T2654 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 608416 T2686 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 608416 T2659 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 608417 T2700 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 608417 T2672 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 608421 T2632 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 608421 T2632 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 608421 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 608496 T2632 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 608498 T2632 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:42426
[junit4:junit4] 2> 608498 T2632 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 608499 T2632 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 608499 T2632 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841
[junit4:junit4] 2> 608499 T2632 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/solr.xml
[junit4:junit4] 2> 608500 T2632 oasc.CoreContainer.<init> New CoreContainer 7890686
[junit4:junit4] 2> 608500 T2632 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/'
[junit4:junit4] 2> 608500 T2632 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/'
[junit4:junit4] 2> 608551 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841
[junit4:junit4] 2> 608552 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/collection1
[junit4:junit4] 2> 608553 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/collection1/conf
[junit4:junit4] 2> 608561 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/collection1/conf/xslt
[junit4:junit4] 2> 608581 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/collection1/lib
[junit4:junit4] 2> 608582 T2632 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/collection1/lib/classes
[junit4:junit4] 2> 608584 T2632 oasc.SolrCoreDiscoverer.addCore Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/conf/core.properties, adding to cores
[junit4:junit4] 2> 608586 T2632 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 608586 T2632 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 608587 T2632 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 608587 T2632 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 608587 T2632 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 608588 T2632 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 608588 T2632 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 608588 T2632 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 608589 T2632 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 608589 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 608593 T2632 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 608593 T2632 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52762/solr
[junit4:junit4] 2> 608594 T2632 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 608594 T2632 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 608596 T2712 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55e2dc name:ZooKeeperConnection Watcher:127.0.0.1:52762 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 608596 T2632 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 608597 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 608600 T2632 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 608602 T2714 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14fe501 name:ZooKeeperConnection Watcher:127.0.0.1:52762/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 608602 T2632 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 608605 T2632 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 609607 T2632 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42426_je%2Fmw
[junit4:junit4] 2> 609608 T2632 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42426_je%2Fmw
[junit4:junit4] 2> 609610 T2654 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 609611 T2672 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 609611 T2700 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 609611 T2659 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 609611 T2714 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 609611 T2686 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 609614 T2632 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 609614 T2632 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 609615 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 609620 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 609624 T2666 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 609626 T2654 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 609627 T2656 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
[junit4:junit4] 2> "operation":"createcollection",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "maxShardsPerNode":null,
[junit4:junit4] 2> "createNodeSet":null,
[junit4:junit4] 2> "name":"nodes_used_collection",
[junit4:junit4] 2> "replicationFactor":"2"}
[junit4:junit4] 2> 609627 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard1_replica1 as part of slice shard1 of collection nodes_used_collection on 127.0.0.1:42496_je%2Fmw
[junit4:junit4] 2> 609628 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard1_replica2 as part of slice shard1 of collection nodes_used_collection on 127.0.0.1:44782_je%2Fmw
[junit4:junit4] 2> 609628 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard2_replica1 as part of slice shard2 of collection nodes_used_collection on 127.0.0.1:60580_je%2Fmw
[junit4:junit4] 2> 609628 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard2_replica2 as part of slice shard2 of collection nodes_used_collection on 127.0.0.1:42426_je%2Fmw
[junit4:junit4] 2> 609629 T2665 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 609630 T2665 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 609629 T2682 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 609630 T2665 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 609630 T2649 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 609631 T2649 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 609630 T2710 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 609631 T2710 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 609631 T2665 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 609632 T2710 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 609630 T2682 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 609633 T2710 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 609633 T2665 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 609633 T2682 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 609634 T2710 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 609634 T2665 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 609634 T2710 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 609634 T2682 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 609636 T2665 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 609637 T2710 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 609636 T2682 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 609637 T2682 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 609638 T2665 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/nodes_used_collection_shard1_replica1/'
[junit4:junit4] 2> 609638 T2710 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/nodes_used_collection_shard2_replica2/'
[junit4:junit4] 2> 609639 T2682 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 609640 T2682 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/nodes_used_collection_shard1_replica2/'
[junit4:junit4] 2> 609643 T2649 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 609644 T2649 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 609645 T2649 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/nodes_used_collection_shard2_replica1/'
[junit4:junit4] 2> 609679 T2710 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 609680 T2649 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 609681 T2665 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 609684 T2682 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 609716 T2649 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 609721 T2649 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 609722 T2710 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 609723 T2710 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 609725 T2649 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica1] Schema name=test
[junit4:junit4] 2> 609727 T2710 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica2] Schema name=test
[junit4:junit4] 2> 609740 T2665 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 609741 T2665 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 609743 T2682 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 609744 T2682 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 609747 T2665 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica1] Schema name=test
[junit4:junit4] 2> 609750 T2682 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica2] Schema name=test
[junit4:junit4] 2> 610193 T2649 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 610201 T2649 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 610206 T2649 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 610222 T2649 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 610227 T2649 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 610232 T2649 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 610233 T2649 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 610233 T2649 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 610234 T2649 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 610235 T2649 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 610235 T2649 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 610235 T2649 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 610236 T2649 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/nodes_used_collection_shard2_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/nodes_used_collection_shard2_replica1/data/
[junit4:junit4] 2> 610236 T2649 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@13b5a3a
[junit4:junit4] 2> 610236 T2649 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 610237 T2649 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/nodes_used_collection_shard2_replica1/data
[junit4:junit4] 2> 610237 T2649 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/nodes_used_collection_shard2_replica1/data/index/
[junit4:junit4] 2> 610238 T2649 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/nodes_used_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 610238 T2649 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/nodes_used_collection_shard2_replica1/data/index
[junit4:junit4] 2> 610240 T2649 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1ef8919 lockFactory=org.apache.lucene.store.NativeFSLockFactory@17453),segFN=segments_1,generation=1}
[junit4:junit4] 2> 610240 T2649 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 610242 T2649 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 610242 T2649 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 610243 T2649 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 610244 T2649 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 610244 T2649 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 610245 T2649 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 610245 T2649 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 610245 T2649 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 610246 T2649 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 610248 T2649 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 610250 T2649 oass.SolrIndexSearcher.<init> Opening Searcher@c92ff main
[junit4:junit4] 2> 610251 T2649 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/nodes_used_collection_shard2_replica1/data/tlog
[junit4:junit4] 2> 610251 T2649 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 610252 T2649 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 610256 T2720 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@c92ff main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 610257 T2649 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=down
[junit4:junit4] 2> 610259 T2710 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 610264 T2710 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 610267 T2710 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 610278 T2665 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 610284 T2665 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 610287 T2665 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 610328 T2682 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 610331 T2665 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 610331 T2710 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 610335 T2682 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 610337 T2710 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 610337 T2665 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 610338 T2682 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 610342 T2710 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 610342 T2665 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 610343 T2710 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 610343 T2710 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 610343 T2710 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 610344 T2665 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 610344 T2665 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 610344 T2665 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 610345 T2710 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 610345 T2710 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 610346 T2710 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 610346 T2665 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 610346 T2665 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 610346 T2710 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/nodes_used_collection_shard2_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/nodes_used_collection_shard2_replica2/data/
[junit4:junit4] 2> 610347 T2665 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 610347 T2710 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@13b5a3a
[junit4:junit4] 2> 610347 T2665 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/nodes_used_collection_shard1_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/nodes_used_collection_shard1_replica1/data/
[junit4:junit4] 2> 610348 T2710 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 610348 T2665 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@13b5a3a
[junit4:junit4] 2> 610349 T2665 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 610349 T2710 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/nodes_used_collection_shard2_replica2/data
[junit4:junit4] 2> 610350 T2665 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/nodes_used_collection_shard1_replica1/data
[junit4:junit4] 2> 610350 T2665 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/nodes_used_collection_shard1_replica1/data/index/
[junit4:junit4] 2> 610350 T2710 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/nodes_used_collection_shard2_replica2/data/index/
[junit4:junit4] 2> 610351 T2665 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/nodes_used_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 610351 T2710 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/nodes_used_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 610352 T2665 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/nodes_used_collection_shard1_replica1/data/index
[junit4:junit4] 2> 610352 T2710 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/nodes_used_collection_shard2_replica2/data/index
[junit4:junit4] 2> 610354 T2665 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@72d74d lockFactory=org.apache.lucene.store.NativeFSLockFactory@10e3495),segFN=segments_1,generation=1}
[junit4:junit4] 2> 610354 T2710 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@222b20 lockFactory=org.apache.lucene.store.NativeFSLockFactory@12902ea),segFN=segments_1,generation=1}
[junit4:junit4] 2> 610355 T2710 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 610355 T2665 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 610356 T2682 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 610357 T2710 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 610358 T2665 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 610358 T2710 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 610358 T2665 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 610359 T2710 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 610359 T2665 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 610360 T2710 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 610360 T2665 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 610361 T2710 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 610361 T2710 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 610361 T2665 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 610362 T2665 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 610362 T2710 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 610362 T2665 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 610363 T2710 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 610363 T2682 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 610363 T2710 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 610363 T2665 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 610365 T2665 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 610367 T2710 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 610367 T2665 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 610368 T2682 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 610370 T2710 oass.SolrIndexSearcher.<init> Opening Searcher@1635a21 main
[junit4:junit4] 2> 610370 T2665 oass.SolrIndexSearcher.<init> Opening Searcher@52895d main
[junit4:junit4] 2> 610370 T2682 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 610371 T2682 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 610371 T2665 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/nodes_used_collection_shard1_replica1/data/tlog
[junit4:junit4] 2> 610370 T2710 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/nodes_used_collection_shard2_replica2/data/tlog
[junit4:junit4] 2> 610372 T2665 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 610371 T2682 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 610373 T2665 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 610373 T2710 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 610374 T2710 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 610374 T2682 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 610375 T2682 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 610375 T2682 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 610376 T2682 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/nodes_used_collection_shard1_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/nodes_used_collection_shard1_replica2/data/
[junit4:junit4] 2> 610376 T2682 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@13b5a3a
[junit4:junit4] 2> 610377 T2682 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 610377 T2722 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@52895d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 610378 T2682 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/nodes_used_collection_shard1_replica2/data
[junit4:junit4] 2> 610378 T2721 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@1635a21 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 610378 T2682 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/nodes_used_collection_shard1_replica2/data/index/
[junit4:junit4] 2> 610378 T2682 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/nodes_used_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 610379 T2682 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/nodes_used_collection_shard1_replica2/data/index
[junit4:junit4] 2> 610379 T2665 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=down
[junit4:junit4] 2> 610379 T2710 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=down
[junit4:junit4] 2> 610381 T2682 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1d526e5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@184e435),segFN=segments_1,generation=1}
[junit4:junit4] 2> 610382 T2682 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 610384 T2682 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 610385 T2682 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 610385 T2682 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 610386 T2682 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 610387 T2682 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 610387 T2682 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 610388 T2682 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 610389 T2682 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 610389 T2682 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 610392 T2682 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 610397 T2682 oass.SolrIndexSearcher.<init> Opening Searcher@1a2b1f6 main
[junit4:junit4] 2> 610397 T2682 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/nodes_used_collection_shard1_replica2/data/tlog
[junit4:junit4] 2> 610398 T2682 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 610398 T2682 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 610402 T2723 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@1a2b1f6 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 610404 T2682 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=down
[junit4:junit4] 2> 610887 T2655 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 610887 T2655 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard2_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:60580_je%2Fmw",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:60580/je/mw"}
[junit4:junit4] 2> 610888 T2655 oasc.Overseer$ClusterStateUpdater.createCollection Create collection nodes_used_collection with numShards 2
[junit4:junit4] 2> 610890 T2655 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard1_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42496_je%2Fmw",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42496/je/mw"}
[junit4:junit4] 2> 610892 T2655 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard2_replica2",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42426_je%2Fmw",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42426/je/mw"}
[junit4:junit4] 2> 610894 T2655 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard1_replica2",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:44782_je%2Fmw",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44782/je/mw"}
[junit4:junit4] 2> 610918 T2700 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 610918 T2686 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 610918 T2672 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 610918 T2654 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 610918 T2659 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 610918 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 611318 T2649 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 611319 T2649 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:60580/je/mw collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 611320 T2649 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4:junit4] 2> 611326 T2649 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 611328 T2649 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179999
[junit4:junit4] 2> 611381 T2665 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 611382 T2710 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 611382 T2710 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica2 address:http://127.0.0.1:42426/je/mw collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 611382 T2665 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica1 address:http://127.0.0.1:42496/je/mw collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 611383 T2665 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4:junit4] 2> 611388 T2665 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 611390 T2665 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179999
[junit4:junit4] 2> 611406 T2682 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 611406 T2682 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica2 address:http://127.0.0.1:44782/je/mw collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 611829 T2649 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 611829 T2649 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 611830 T2649 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:60580/je/mw/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 611830 T2649 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:60580/je/mw START replicas=[http://127.0.0.1:42426/je/mw/nodes_used_collection_shard2_replica2/] nUpdates=100
[junit4:junit4] 2> 611831 T2649 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:60580/je/mw DONE. We have no versions. sync failed.
[junit4:junit4] 2> 611831 T2649 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 611832 T2649 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:junit4] 2> 611832 T2649 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:60580/je/mw/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 611832 T2649 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard2
[junit4:junit4] 2> ASYNC NEW_CORE C699 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@abae1f url=http://127.0.0.1:42426/je/mw/nodes_used_collection_shard2_replica2 node=127.0.0.1:42426_je%2Fmw C699_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica2 props:{shard=shard2, state=down, core=nodes_used_collection_shard2_replica2, collection=nodes_used_collection, node_name=127.0.0.1:42426_je%2Fmw, base_url=http://127.0.0.1:42426/je/mw}
[junit4:junit4] 2> 611838 T2709 C699 P42426 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp=/je/mw path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 611890 T2665 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 611891 T2665 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 611891 T2665 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:42496/je/mw/nodes_used_collection_shard1_replica1/
[junit4:junit4] 2> 611892 T2665 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:42496/je/mw START replicas=[http://127.0.0.1:44782/je/mw/nodes_used_collection_shard1_replica2/] nUpdates=100
[junit4:junit4] 2> 611892 T2665 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:42496/je/mw DONE. We have no versions. sync failed.
[junit4:junit4] 2> 611893 T2665 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 611893 T2665 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:junit4] 2> 611894 T2665 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:42496/je/mw/nodes_used_collection_shard1_replica1/
[junit4:junit4] 2> 611894 T2665 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard1
[junit4:junit4] 2> ASYNC NEW_CORE C700 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@11f5641 url=http://127.0.0.1:44782/je/mw/nodes_used_collection_shard1_replica2 node=127.0.0.1:44782_je%2Fmw C700_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica2 props:{shard=shard1, state=down, core=nodes_used_collection_shard1_replica2, collection=nodes_used_collection, node_name=127.0.0.1:44782_je%2Fmw, base_url=http://127.0.0.1:44782/je/mw}
[junit4:junit4] 2> 611899 T2681 C700 P44782 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp=/je/mw path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 612426 T2655 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 612437 T2654 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 612437 T2672 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 612437 T2659 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 612437 T2686 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 612437 T2700 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 612437 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 612440 T2682 oasc.ZkController.register We are http://127.0.0.1:44782/je/mw/nodes_used_collection_shard1_replica2/ and leader is http://127.0.0.1:42496/je/mw/nodes_used_collection_shard1_replica1/
[junit4:junit4] 2> 612440 T2682 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica2 baseURL=http://127.0.0.1:44782/je/mw
[junit4:junit4] 2> 612440 T2682 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 612441 T2682 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 612441 T2726 C700 P44782 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard1_replica2 recoveringAfterStartup=true
[junit4:junit4] 2> 612441 T2726 C700 P44782 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 612441 T2682 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 612441 T2726 C700 P44782 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=recovering
[junit4:junit4] 2> 612443 T2710 oasc.ZkController.register We are http://127.0.0.1:42426/je/mw/nodes_used_collection_shard2_replica2/ and leader is http://127.0.0.1:60580/je/mw/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 612444 T2710 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica2 baseURL=http://127.0.0.1:42426/je/mw
[junit4:junit4] 2> 612444 T2682 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard1&name=nodes_used_collection_shard1_replica2&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=2815
[junit4:junit4] 2> 612444 T2726 C700 P44782 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 612444 T2710 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 612445 T2710 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 612446 T2727 C699 P42426 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard2_replica2 recoveringAfterStartup=true
[junit4:junit4] 2> 612446 T2710 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 612447 T2727 C699 P42426 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 612447 T2710 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard2&name=nodes_used_collection_shard2_replica2&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=2817
[junit4:junit4] 2> 612448 T2727 C699 P42426 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=recovering
[junit4:junit4] 2> 612450 T2727 C699 P42426 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 612451 T2668 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:44782_je%2Fmw_nodes_used_collection_shard1_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 612452 T2665 oasc.ZkController.register We are http://127.0.0.1:42496/je/mw/nodes_used_collection_shard1_replica1/ and leader is http://127.0.0.1:42496/je/mw/nodes_used_collection_shard1_replica1/
[junit4:junit4] 2> 612452 T2665 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica1 baseURL=http://127.0.0.1:42496/je/mw
[junit4:junit4] 2> 612453 T2665 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 612453 T2665 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=active
[junit4:junit4] 2> 612454 T2647 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:42426_je%2Fmw_nodes_used_collection_shard2_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 612455 T2665 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 612456 T2665 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard1&name=nodes_used_collection_shard1_replica1&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=2827
[junit4:junit4] 2> 612490 T2649 oasc.ZkController.register We are http://127.0.0.1:60580/je/mw/nodes_used_collection_shard2_replica1/ and leader is http://127.0.0.1:60580/je/mw/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 612491 T2649 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica1 baseURL=http://127.0.0.1:60580/je/mw
[junit4:junit4] 2> 612491 T2649 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 612491 T2649 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=active
[junit4:junit4] 2> 612493 T2649 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 612493 T2649 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard2&name=nodes_used_collection_shard2_replica1&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=2863
[junit4:junit4] 2> 612494 T2656 oasc.OverseerCollectionProcessor.createCollection Finished create command on all shards for collection: nodes_used_collection
[junit4:junit4] 2> 612496 T2672 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work/qnr-0000000000 state: SyncConnected type NodeDataChanged
[junit4:junit4] 2> 612497 T2654 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 612497 T2656 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000000 complete, response:{success={null={responseHeader={status=0,QTime=2817},core=nodes_used_collection_shard2_replica2},null={responseHeader={status=0,QTime=2815},core=nodes_used_collection_shard1_replica2},null={responseHeader={status=0,QTime=2827},core=nodes_used_collection_shard1_replica1},null={responseHeader={status=0,QTime=2863},core=nodes_used_collection_shard2_replica1}}}
[junit4:junit4] 2> 612501 T2666 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/collections params={numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2} status=0 QTime=2878
[junit4:junit4] 2> 612501 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 612502 T2632 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 612504 T2729 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71f513 name:ZooKeeperConnection Watcher:127.0.0.1:52762/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 612504 T2632 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 612505 T2632 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 612507 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 612508 T2632 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 612509 T2731 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f25ecd name:ZooKeeperConnection Watcher:127.0.0.1:52762/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 612510 T2632 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 612511 T2632 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 612515 T2709 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&maxShardsPerNode=2&name=awholynewcollection_0&replicationFactor=3&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 612516 T2654 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 612517 T2656 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000002 message:{
[junit4:junit4] 2> "operation":"createcollection",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "maxShardsPerNode":"2",
[junit4:junit4] 2> "createNodeSet":null,
[junit4:junit4] 2> "name":"awholynewcollection_0",
[junit4:junit4] 2> "replicationFactor":"3"}
[junit4:junit4] 2> 612517 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica1 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:42426_je%2Fmw
[junit4:junit4] 2> 612517 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica2 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:42496_je%2Fmw
[junit4:junit4] 2> 612517 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica3 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:60580_je%2Fmw
[junit4:junit4] 2> 612518 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica1 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:44782_je%2Fmw
[junit4:junit4] 2> 612518 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica2 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:35800_je%2Fmw
[junit4:junit4] 2> 612518 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica3 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:42426_je%2Fmw
[junit4:junit4] 2> 612519 T2665 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/awholynewcollection_0_shard1_replica2
[junit4:junit4] 2> 612519 T2665 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 612519 T2707 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_0_shard1_replica1
[junit4:junit4] 2> 612519 T2693 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/awholynewcollection_0_shard2_replica2
[junit4:junit4] 2> 612520 T2665 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 612520 T2693 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 612520 T2707 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 612520 T2680 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/awholynewcollection_0_shard2_replica1
[junit4:junit4] 2> 612521 T2707 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 612519 T2650 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica3' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/awholynewcollection_0_shard1_replica3
[junit4:junit4] 2> 612522 T2650 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 612519 T2710 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica3' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_0_shard2_replica3
[junit4:junit4] 2> 612523 T2650 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 612523 T2710 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 612522 T2707 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 612521 T2680 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 612521 T2693 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 612521 T2665 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 612524 T2707 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 612525 T2707 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 612524 T2693 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 612524 T2680 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 612523 T2710 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 612523 T2650 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 612526 T2693 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 612527 T2693 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 612526 T2710 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 612526 T2680 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 612525 T2665 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 612527 T2707 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 612527 T2650 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 612528 T2693 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 612528 T2710 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 612528 T2665 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 612530 T2707 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_0_shard1_replica1/'
[junit4:junit4] 2> 612530 T2693 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/awholynewcollection_0_shard2_replica2/'
[junit4:junit4] 2> 612531 T2710 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 612532 T2665 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 612535 T2665 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/awholynewcollection_0_shard1_replica2/'
[junit4:junit4] 2> 612529 T2680 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 612532 T2710 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_0_shard2_replica3/'
[junit4:junit4] 2> 612530 T2650 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 612540 T2680 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 612541 T2650 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/awholynewcollection_0_shard1_replica3/'
[junit4:junit4] 2> 612545 T2680 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/awholynewcollection_0_shard2_replica1/'
[junit4:junit4] 2> 612569 T2707 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 612575 T2665 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 612581 T2693 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 612589 T2680 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 612602 T2710 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 612606 T2650 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 612631 T2707 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 612633 T2707 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 612639 T2707 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica1] Schema name=test
[junit4:junit4] 2> 612643 T2680 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 612644 T2680 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 612646 T2665 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 612648 T2665 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 612650 T2693 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 612650 T2680 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica1] Schema name=test
[junit4:junit4] 2> 612651 T2693 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 612654 T2665 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica2] Schema name=test
[junit4:junit4] 2> 612657 T2693 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica2] Schema name=test
[junit4:junit4] 2> 612660 T2650 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 612660 T2710 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 612662 T2650 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 612662 T2710 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 612668 T2650 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica3] Schema name=test
[junit4:junit4] 2> 612668 T2710 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica3] Schema name=test
[junit4:junit4] 2> 613258 T2707 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 613267 T2707 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 613271 T2707 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 613276 T2665 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 613281 T2680 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 613284 T2665 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 613288 T2665 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 613288 T2680 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 613292 T2680 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 613301 T2665 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 613305 T2665 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 613306 T2707 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 613307 T2693 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 613308 T2680 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 613309 T2665 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 613311 T2665 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 613311 T2665 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 613312 T2665 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 613313 T2680 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 613314 T2665 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 613314 T2665 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 613315 T2665 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 613315 T2693 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 613318 T2680 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 613315 T2665 oasc.SolrCore.<init> [awholynewcollection_0_shard1_replica2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/awholynewcollection_0_shard1_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/awholynewcollection_0_shard1_replica2/data/
[junit4:junit4] 2> 613321 T2665 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@13b5a3a
[junit4:junit4] 2> 613321 T2665 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 613322 T2665 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/awholynewcollection_0_shard1_replica2/data
[junit4:junit4] 2> 613315 T2707 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 613320 T2680 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 613323 T2680 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 613323 T2665 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/awholynewcollection_0_shard1_replica2/data/index/
[junit4:junit4] 2> 613324 T2665 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard1_replica2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/awholynewcollection_0_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 613323 T2693 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 613323 T2680 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 613327 T2680 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 613328 T2680 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 613328 T2665 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/awholynewcollection_0_shard1_replica2/data/index
[junit4:junit4] 2> 613328 T2680 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 613329 T2680 oasc.SolrCore.<init> [awholynewcollection_0_shard2_replica1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/awholynewcollection_0_shard2_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/awholynewcollection_0_shard2_replica1/data/
[junit4:junit4] 2> 613330 T2680 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@13b5a3a
[junit4:junit4] 2> 613328 T2707 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 613330 T2680 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 613331 T2665 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@14b3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@188b3ad),segFN=segments_1,generation=1}
[junit4:junit4] 2> 613331 T2665 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 613332 T2707 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 613331 T2680 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/awholynewcollection_0_shard2_replica1/data
[junit4:junit4] 2> 613333 T2680 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/awholynewcollection_0_shard2_replica1/data/index/
[junit4:junit4] 2> 613333 T2680 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard2_replica1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/awholynewcollection_0_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 613334 T2680 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/awholynewcollection_0_shard2_replica1/data/index
[junit4:junit4] 2> 613334 T2665 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 613335 T2665 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 613336 T2665 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 613336 T2665 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 613337 T2665 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 613337 T2665 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 613338 T2665 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 613339 T2665 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 613339 T2665 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 613340 T2693 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 613332 T2707 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 613336 T2680 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1eab6a8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1ea6d00),segFN=segments_1,generation=1}
[junit4:junit4] 2> 613341 T2680 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 613342 T2665 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 613344 T2680 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 613344 T2680 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 613341 T2707 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 613345 T2680 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 613345 T2680 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 613346 T2707 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 613346 T2707 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 613346 T2680 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 613347 T2707 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 613347 T2707 oasc.SolrCore.<init> [awholynewcollection_0_shard1_replica1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_0_shard1_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_0_shard1_replica1/data/
[junit4:junit4] 2> 613348 T2707 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@13b5a3a
[junit4:junit4] 2> 613346 T2693 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 613353 T2710 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 613352 T2665 oass.SolrIndexSearcher.<init> Opening Searcher@89c61 main
[junit4:junit4] 2> 613352 T2707 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 613347 T2680 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 613354 T2665 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/awholynewcollection_0_shard1_replica2/data/tlog
[junit4:junit4] 2> 613355 T2707 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_0_shard1_replica1/data
[junit4:junit4] 2> 613355 T2680 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 613356 T2665 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 613356 T2707 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_0_shard1_replica1/data/index/
[junit4:junit4] 2> 613356 T2680 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 613356 T2665 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 613357 T2680 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 613357 T2707 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard1_replica1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_0_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 613358 T2707 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_0_shard1_replica1/data/index
[junit4:junit4] 2> 613359 T2707 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@14858e2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@125604d),segFN=segments_1,generation=1}
[junit4:junit4] 2> 613360 T2680 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 613360 T2707 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 613360 T2734 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard1_replica2] Registered new searcher Searcher@89c61 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 613362 T2707 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 613362 T2707 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 613362 T2710 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 613363 T2707 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 613363 T2665 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica2 state=down
[junit4:junit4] 2> 613363 T2707 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 613364 T2680 oass.SolrIndexSearcher.<init> Opening Searcher@1c70f96 main
[junit4:junit4] 2> 613364 T2707 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 613365 T2707 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 613364 T2680 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/awholynewcollection_0_shard2_replica1/data/tlog
[junit4:junit4] 2> 613365 T2707 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 613366 T2680 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 613366 T2707 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 613366 T2710 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 613366 T2680 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 613367 T2707 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 613368 T2693 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 613370 T2707 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 613370 T2693 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 613370 T2693 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 613371 T2693 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 613372 T2707 oass.SolrIndexSearcher.<init> Opening Searcher@1a594a1 main
[junit4:junit4] 2> 613372 T2693 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 613373 T2693 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 613373 T2735 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard2_replica1] Registered new searcher Searcher@1c70f96 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 613373 T2707 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_0_shard1_replica1/data/tlog
[junit4:junit4] 2> 613373 T2693 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 613374 T2707 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 613374 T2693 oasc.SolrCore.<init> [awholynewcollection_0_shard2_replica2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/awholynewcollection_0_shard2_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/awholynewcollection_0_shard2_replica2/data/
[junit4:junit4] 2> 613375 T2680 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica1 state=down
[junit4:junit4] 2> 613375 T2707 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 613375 T2693 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@13b5a3a
[junit4:junit4] 2> 613376 T2693 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 613377 T2693 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/awholynewcollection_0_shard2_replica2/data
[junit4:junit4] 2> 613378 T2693 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/awholynewcollection_0_shard2_replica2/data/index/
[junit4:junit4] 2> 613378 T2710 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 613378 T2693 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard2_replica2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/awholynewcollection_0_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 613379 T2693 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/awholynewcollection_0_shard2_replica2/data/index
[junit4:junit4] 2> 613379 T2736 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard1_replica1] Registered new searcher Searcher@1a594a1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 613381 T2707 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica1 state=down
[junit4:junit4] 2> 613381 T2693 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1e5f6f8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c7d366),segFN=segments_1,generation=1}
[junit4:junit4] 2> 613381 T2710 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 613382 T2693 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 613384 T2693 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 613385 T2693 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 613385 T2710 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 613385 T2693 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 613386 T2710 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 613386 T2710 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 613386 T2693 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 613387 T2710 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 613387 T2693 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 613388 T2693 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 613388 T2710 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 613388 T2710 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 613388 T2693 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 613389 T2710 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 613389 T2710 oasc.SolrCore.<init> [awholynewcollection_0_shard2_replica3] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_0_shard2_replica3/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_0_shard2_replica3/data/
[junit4:junit4] 2> 613389 T2693 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 613389 T2710 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@13b5a3a
[junit4:junit4] 2> 613390 T2693 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 613390 T2710 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 613391 T2710 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_0_shard2_replica3/data
[junit4:junit4] 2> 613391 T2710 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_0_shard2_replica3/data/index/
[junit4:junit4] 2> 613391 T2710 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard2_replica3] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_0_shard2_replica3/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 613392 T2710 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_0_shard2_replica3/data/index
[junit4:junit4] 2> 613393 T2693 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 613393 T2710 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@996dd7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@18819e4),segFN=segments_1,generation=1}
[junit4:junit4] 2> 613394 T2710 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 613395 T2710 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 613396 T2710 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 613396 T2693 oass.SolrIndexSearcher.<init> Opening Searcher@4160c4 main
[junit4:junit4] 2> 613396 T2710 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 613397 T2693 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/awholynewcollection_0_shard2_replica2/data/tlog
[junit4:junit4] 2> 613397 T2710 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 613398 T2693 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 613398 T2710 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 613398 T2710 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 613398 T2693 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 613399 T2710 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 613400 T2710 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 613400 T2710 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 613402 T2710 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 613402 T2737 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard2_replica2] Registered new searcher Searcher@4160c4 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 613404 T2710 oass.SolrIndexSearcher.<init> Opening Searcher@14f8da5 main
[junit4:junit4] 2> 613404 T2710 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_0_shard2_replica3/data/tlog
[junit4:junit4] 2> 613404 T2693 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica2 state=down
[junit4:junit4] 2> 613405 T2710 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 613405 T2650 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 613405 T2710 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 613409 T2738 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard2_replica3] Registered new searcher Searcher@14f8da5 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 613410 T2710 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica3 state=down
[junit4:junit4] 2> 613411 T2650 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 613414 T2650 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 613423 T2650 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 613426 T2650 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 613429 T2650 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 613430 T2650 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 613430 T2650 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 613431 T2650 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 613432 T2650 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 613432 T2650 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 613432 T2650 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 613433 T2650 oasc.SolrCore.<init> [awholynewcollection_0_shard1_replica3] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/awholynewcollection_0_shard1_replica3/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/awholynewcollection_0_shard1_replica3/data/
[junit4:junit4] 2> 613433 T2650 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@13b5a3a
[junit4:junit4] 2> 613433 T2650 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 613434 T2650 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/awholynewcollection_0_shard1_replica3/data
[junit4:junit4] 2> 613434 T2650 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/awholynewcollection_0_shard1_replica3/data/index/
[junit4:junit4] 2> 613434 T2650 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard1_replica3] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/awholynewcollection_0_shard1_replica3/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 613435 T2650 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/awholynewcollection_0_shard1_replica3/data/index
[junit4:junit4] 2> 613436 T2650 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@cedda9 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6f040f),segFN=segments_1,generation=1}
[junit4:junit4] 2> 613437 T2650 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 613438 T2650 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 613438 T2650 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 613439 T2650 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 613439 T2650 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 613440 T2650 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 613440 T2650 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 613440 T2650 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 613441 T2650 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 613441 T2650 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 613443 T2650 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 613445 T2650 oass.SolrIndexSearcher.<init> Opening Searcher@b4fe40 main
[junit4:junit4] 2> 613446 T2650 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/awholynewcollection_0_shard1_replica3/data/tlog
[junit4:junit4] 2> 613446 T2650 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 613447 T2650 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 613450 T2739 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard1_replica3] Registered new searcher Searcher@b4fe40 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 613452 T2650 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica3 state=down
[junit4:junit4] 2> 613948 T2655 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 613948 T2655 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:44782_je%2Fmw_nodes_used_collection_shard1_replica2",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard1_replica2",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:44782_je%2Fmw",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44782/je/mw"}
[junit4:junit4] 2> 613952 T2655 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:42426_je%2Fmw_nodes_used_collection_shard2_replica2",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard2_replica2",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42426_je%2Fmw",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42426/je/mw"}
[junit4:junit4] 2> 613954 T2655 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:42496_je%2Fmw_nodes_used_collection_shard1_replica1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard1_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42496_je%2Fmw",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42496/je/mw"}
[junit4:junit4] 2> 613957 T2655 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:60580_je%2Fmw_nodes_used_collection_shard2_replica1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard2_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:60580_je%2Fmw",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:60580/je/mw"}
[junit4:junit4] 2> 613959 T2655 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard1_replica2",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42496_je%2Fmw",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42496/je/mw"}
[junit4:junit4] 2> 613959 T2655 oasc.Overseer$ClusterStateUpdater.createCollection Create collection awholynewcollection_0 with numShards 2
[junit4:junit4] 2> 613962 T2655 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard2_replica1",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:44782_je%2Fmw",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44782/je/mw"}
[junit4:junit4] 2> 613964 T2655 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard1_replica1",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42426_je%2Fmw",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42426/je/mw"}
[junit4:junit4] 2> 613967 T2655 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard2_replica2",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:35800_je%2Fmw",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:35800/je/mw"}
[junit4:junit4] 2> 613969 T2655 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard2_replica3",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42426_je%2Fmw",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42426/je/mw"}
[junit4:junit4] 2> 613971 T2655 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard1_replica3",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:60580_je%2Fmw",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:60580/je/mw"}
[junit4:junit4] 2> 613977 T2686 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 613977 T2731 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 613977 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 613977 T2700 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 613977 T2672 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 613977 T2659 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 613977 T2654 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 613977 T2729 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 614365 T2665 oasc.CoreContainer.registerCore registering core: awholynewcollection_0_shard1_replica2
[junit4:junit4] 2> 614365 T2665 oasc.ZkController.register Register replica - core:awholynewcollection_0_shard1_replica2 address:http://127.0.0.1:42496/je/mw collection:awholynewcollection_0 shard:shard1
[junit4:junit4] 2> 614367 T2665 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0/leader_elect/shard1/election
[junit4:junit4] 2> 614376 T2665 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 614376 T2680 oasc.CoreContainer.registerCore registering core: awholynewcollection_0_shard2_replica1
[junit4:junit4] 2> 614377 T2680 oasc.ZkController.register Register replica - core:awholynewcollection_0_shard2_replica1 address:http://127.0.0.1:44782/je/mw collection:awholynewcollection_0 shard:shard2
[junit4:junit4] 2> 614378 T2680 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0/leader_elect/shard2/election
[junit4:junit4] 2> 614379 T2665 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=3 found=1 timeoutin=180000
[junit4:junit4] 2> 614382 T2707 oasc.CoreContainer.registerCore registering core: awholynewcollection_0_shard1_replica1
[junit4:junit4] 2> 614382 T2707 oasc.ZkController.register Register replica - core:awholynewcollection_0_shard1_replica1 address:http://127.0.0.1:42426/je/mw collection:awholynewcollection_0 shard:shard1
[junit4:junit4] 2> 614383 T2680 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 614386 T2680 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=3 found=1 timeoutin=180000
[junit4:junit4] 2> 614406 T2693 oasc.CoreContainer.registerCore registering core: awholynewcollection_0_shard2_replica2
[junit4:junit4] 2> 614407 T2693 oasc.ZkController.register Register replica - core:awholynewcollection_0_shard2_replica2 address:http://127.0.0.1:35800/je/mw collection:awholynewcollection_0 shard:shard2
[junit4:junit4] 2> 614411 T2710 oasc.CoreContainer.registerCore registering core: awholynewcollection_0_shard2_replica3
[junit4:junit4] 2> 614412 T2710 oasc.ZkController.register Register replica - core:awholynewcollection_0_shard2_replica3 address:http://127.0.0.1:42426/je/mw collection:awholynewcollection_0 shard:shard2
[junit4:junit4] 2> 614451 T2668 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:44782_je%2Fmw_nodes_used_collection_shard1_replica2, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 614452 T2668 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:44782_je%252Fmw_nodes_used_collection_shard1_replica2&state=recovering&nodeName=127.0.0.1:44782_je%252Fmw&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard1_replica1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2002
[junit4:junit4] 2> 614454 T2647 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:42426_je%2Fmw_nodes_used_collection_shard2_replica2, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 614455 T2647 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:42426_je%252Fmw_nodes_used_collection_shard2_replica2&state=recovering&nodeName=127.0.0.1:42426_je%252Fmw&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard2_replica1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2001
[junit4:junit4] 2> 614552 T2650 oasc.CoreContainer.registerCore registering core: awholynewcollection_0_shard1_replica3
[junit4:junit4] 2> 614552 T2650 oasc.ZkController.register Register replica - core:awholynewcollection_0_shard1_replica3 address:http://127.0.0.1:60580/je/mw collection:awholynewcollection_0 shard:shard1
[junit4:junit4] 2> 614880 T2665 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 614881 T2665 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 614881 T2665 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:42496/je/mw/awholynewcollection_0_shard1_replica2/
[junit4:junit4] 2> 614881 T2665 oasu.PeerSync.sync PeerSync: core=awholynewcollection_0_shard1_replica2 url=http://127.0.0.1:42496/je/mw START replicas=[http://127.0.0.1:42426/je/mw/awholynewcollection_0_shard1_replica1/, http://127.0.0.1:60580/je/mw/awholynewcollection_0_shard1_replica3/] nUpdates=100
[junit4:junit4] 2> 614882 T2665 oasu.PeerSync.sync PeerSync: core=awholynewcollection_0_shard1_replica2 url=http://127.0.0.1:42496/je/mw DONE. We have no versions. sync failed.
[junit4:junit4] 2> 614882 T2665 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 614882 T2665 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:junit4] 2> 614883 T2665 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:42496/je/mw/awholynewcollection_0_shard1_replica2/
[junit4:junit4] 2> 614883 T2665 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0/leaders/shard1
[junit4:junit4] 2> 614887 T2680 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 614888 T2680 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 614888 T2680 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:44782/je/mw/awholynewcollection_0_shard2_replica1/
[junit4:junit4] 2> 614888 T2680 oasu.PeerSync.sync PeerSync: core=awholynewcollection_0_shard2_replica1 url=http://127.0.0.1:44782/je/mw START replicas=[http://127.0.0.1:35800/je/mw/awholynewcollection_0_shard2_replica2/, http://127.0.0.1:42426/je/mw/awholynewcollection_0_shard2_replica3/] nUpdates=100
[junit4:junit4] 2> ASYNC NEW_CORE C701 name=awholynewcollection_0_shard1_replica3 org.apache.solr.core.SolrCore@1e87e0c url=http://127.0.0.1:60580/je/mw/awholynewcollection_0_shard1_replica3 node=127.0.0.1:60580_je%2Fmw C701_STATE=coll:awholynewcollection_0 core:awholynewcollection_0_shard1_replica3 props:{shard=shard1, state=down, core=awholynewcollection_0_shard1_replica3, collection=awholynewcollection_0, node_name=127.0.0.1:60580_je%2Fmw, base_url=http://127.0.0.1:60580/je/mw}
[junit4:junit4] 2> 614889 T2648 C701 P60580 oasc.SolrCore.execute [awholynewcollection_0_shard1_replica3] webapp=/je/mw path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> ASYNC NEW_CORE C702 name=awholynewcollection_0_shard1_replica1 org.apache.solr.core.SolrCore@1841ff8 url=http://127.0.0.1:42426/je/mw/awholynewcollection_0_shard1_replica1 node=127.0.0.1:42426_je%2Fmw C702_STATE=coll:awholynewcollection_0 core:awholynewcollection_0_shard1_replica1 props:{shard=shard1, state=down, core=awholynewcollection_0_shard1_replica1, collection=awholynewcollection_0, node_name=127.0.0.1:42426_je%2Fmw, base_url=http://127.0.0.1:42426/je/mw}
[junit4:junit4] 2> 614889 T2708 C702 P42426 oasc.SolrCore.execute [awholynewcollection_0_shard1_replica1] webapp=/je/mw path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 614889 T2680 oasu.PeerSync.sync PeerSync: core=awholynewcollection_0_shard2_replica1 url=http://127.0.0.1:44782/je/mw DONE. We have no versions. sync failed.
[junit4:junit4] 2> 614890 T2680 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 614891 T2680 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:junit4] 2> 614891 T2680 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:44782/je/mw/awholynewcollection_0_shard2_replica1/
[junit4:junit4] 2> 614892 T2680 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0/leaders/shard2
[junit4:junit4] 2> ASYNC NEW_CORE C703 name=awholynewcollection_0_shard2_replica3 org.apache.solr.core.SolrCore@1069c7f url=http://127.0.0.1:42426/je/mw/awholynewcollection_0_shard2_replica3 node=127.0.0.1:42426_je%2Fmw C703_STATE=coll:awholynewcollection_0 core:awholynewcollection_0_shard2_replica3 props:{shard=shard2, state=down, core=awholynewcollection_0_shard2_replica3, collection=awholynewcollection_0, node_name=127.0.0.1:42426_je%2Fmw, base_url=http://127.0.0.1:42426/je/mw}
[junit4:junit4] 2> 614894 T2744 C703 P42426 oasc.SolrCore.execute [awholynewcollection_0_shard2_replica3] webapp=/je/mw path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> ASYNC NEW_CORE C704 name=awholynewcollection_0_shard2_replica2 org.apache.solr.core.SolrCore@1c10c36 url=http://127.0.0.1:35800/je/mw/awholynewcollection_0_shard2_replica2 node=127.0.0.1:35800_je%2Fmw C704_STATE=coll:awholynewcollection_0 core:awholynewcollection_0_shard2_replica2 props:{shard=shard2, state=down, core=awholynewcollection_0_shard2_replica2, collection=awholynewcollection_0, node_name=127.0.0.1:35800_je%2Fmw, base_url=http://127.0.0.1:35800/je/mw}
[junit4:junit4] 2> 614895 T2694 C704 P35800 oasc.SolrCore.execute [awholynewcollection_0_shard2_replica2] webapp=/je/mw path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 615506 T2655 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 615519 T2654 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 615519 T2729 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 615519 T2659 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 615519 T2700 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 615519 T2731 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 615519 T2686 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 615519 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 615519 T2672 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 615537 T2707 oasc.ZkController.register We are http://127.0.0.1:42426/je/mw/awholynewcollection_0_shard1_replica1/ and leader is http://127.0.0.1:42496/je/mw/awholynewcollection_0_shard1_replica2/
[junit4:junit4] 2> 615537 T2707 oasc.ZkController.register No LogReplay needed for core=awholynewcollection_0_shard1_replica1 baseURL=http://127.0.0.1:42426/je/mw
[junit4:junit4] 2> 615538 T2707 oasc.ZkController.checkRecovery Core needs to recover:awholynewcollection_0_shard1_replica1
[junit4:junit4] 2> 615538 T2707 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 615539 T2745 C702 P42426 oasc.RecoveryStrategy.run Starting recovery process. core=awholynewcollection_0_shard1_replica1 recoveringAfterStartup=true
[junit4:junit4] 2> 615539 T2745 C702 P42426 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 615539 T2745 C702 P42426 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica1 state=recovering
[junit4:junit4] 2> 615539 T2707 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 615540 T2745 C702 P42426 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 615540 T2665 oasc.ZkController.register We are http://127.0.0.1:42496/je/mw/awholynewcollection_0_shard1_replica2/ and leader is http://127.0.0.1:42496/je/mw/awholynewcollection_0_shard1_replica2/
[junit4:junit4] 2> 615540 T2707 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard1&name=awholynewcollection_0_shard1_replica1&action=CREATE&collection=awholynewcollection_0&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=3021
[junit4:junit4] 2> 615540 T2665 oasc.ZkController.register No LogReplay needed for core=awholynewcollection_0_shard1_replica2 baseURL=http://127.0.0.1:42496/je/mw
[junit4:junit4] 2> 615541 T2665 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 615541 T2665 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica2 state=active
[junit4:junit4] 2> 615542 T2665 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 615543 T2665 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard1&name=awholynewcollection_0_shard1_replica2&action=CREATE&collection=awholynewcollection_0&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=3024
[junit4:junit4] 2> 615544 T2668 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:42426_je%2Fmw_awholynewcollection_0_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 615549 T2680 oasc.ZkController.register We are http://127.0.0.1:44782/je/mw/awholynewcollection_0_shard2_replica1/ and leader is http://127.0.0.1:44782/je/mw/awholynewcollection_0_shard2_replica1/
[junit4:junit4] 2> 615550 T2680 oasc.ZkController.register No LogReplay needed for core=awholynewcollection_0_shard2_replica1 baseURL=http://127.0.0.1:44782/je/mw
[junit4:junit4] 2> 615550 T2680 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 615550 T2680 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica1 state=active
[junit4:junit4] 2> 615551 T2680 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 615552 T2680 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard2&name=awholynewcollection_0_shard2_replica1&action=CREATE&collection=awholynewcollection_0&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=3032
[junit4:junit4] 2> 615555 T2650 oasc.ZkController.register We are http://127.0.0.1:60580/je/mw/awholynewcollection_0_shard1_replica3/ and leader is http://127.0.0.1:42496/je/mw/awholynewcollection_0_shard1_replica2/
[junit4:junit4] 2> 615556 T2650 oasc.ZkController.register No LogReplay needed for core=awholynewcollection_0_shard1_replica3 baseURL=http://127.0.0.1:60580/je/mw
[junit4:junit4] 2> 615556 T2650 oasc.ZkController.checkRecovery Core needs to recover:awholynewcollection_0_shard1_replica3
[junit4:junit4] 2> 615556 T2650 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 615557 T2746 C701 P60580 oasc.RecoveryStrategy.run Starting recovery process. core=awholynewcollection_0_shard1_replica3 recoveringAfterStartup=true
[junit4:junit4] 2> 615557 T2746 C701 P60580 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 615557 T2746 C701 P60580 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica3 state=recovering
[junit4:junit4] 2> 615557 T2650 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 615558 T2746 C701 P60580 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 615558 T2650 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard1&name=awholynewcollection_0_shard1_replica3&action=CREATE&collection=awholynewcollection_0&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=3039
[junit4:junit4] 2> 615561 T2665 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:60580_je%2Fmw_awholynewcollection_0_shard1_replica3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 615563 T2693 oasc.ZkController.register We are http://127.0.0.1:35800/je/mw/awholynewcollection_0_shard2_replica2/ and leader is http://127.0.0.1:44782/je/mw/awholynewcollection_0_shard2_replica1/
[junit4:junit4] 2> 615563 T2693 oasc.ZkController.register No LogReplay needed for core=awholynewcollection_0_shard2_replica2 baseURL=http://127.0.0.1:35800/je/mw
[junit4:junit4] 2> 615563 T2693 oasc.ZkController.checkRecovery Core needs to recover:awholynewcollection_0_shard2_replica2
[junit4:junit4] 2> 615563 T2693 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 615564 T2747 C704 P35800 oasc.RecoveryStrategy.run Starting recovery process. core=awholynewcollection_0_shard2_replica2 recoveringAfterStartup=true
[junit4:junit4] 2> 615564 T2747 C704 P35800 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 615564 T2693 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 615564 T2747 C704 P35800 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica2 state=recovering
[junit4:junit4] 2> 615565 T2710 oasc.ZkController.register We are http://127.0.0.1:42426/je/mw/awholynewcollection_0_shard2_replica3/ and leader is http://127.0.0.1:44782/je/mw/awholynewcollection_0_shard2_replica1/
[junit4:junit4] 2> 615565 T2693 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard2&name=awholynewcollection_0_shard2_replica2&action=CREATE&collection=awholynewcollection_0&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=3046
[junit4:junit4] 2> 615565 T2710 oasc.ZkController.register No LogReplay needed for core=awholynewcollection_0_shard2_replica3 baseURL=http://127.0.0.1:42426/je/mw
[junit4:junit4] 2> 615565 T2710 oasc.ZkController.checkRecovery Core needs to recover:awholynewcollection_0_shard2_replica3
[junit4:junit4] 2> 615566 T2710 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 615565 T2747 C704 P35800 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 615566 T2748 C703 P42426 oasc.RecoveryStrategy.run Starting recovery process. core=awholynewcollection_0_shard2_replica3 recoveringAfterStartup=true
[junit4:junit4] 2> 615566 T2748 C703 P42426 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 615566 T2710 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 615566 T2748 C703 P42426 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica3 state=recovering
[junit4:junit4] 2> 615567 T2710 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard2&name=awholynewcollection_0_shard2_replica3&action=CREATE&collection=awholynewcollection_0&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=3048
[junit4:junit4] 2> 615568 T2748 C703 P42426 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 615568 T2656 oasc.OverseerCollectionProcessor.createCollection Finished create command on all shards for collection: awholynewcollection_0
[junit4:junit4] 2> 615569 T2681 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:35800_je%2Fmw_awholynewcollection_0_shard2_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 615570 T2714 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work/qnr-0000000002 state: SyncConnected type NodeDataChanged
[junit4:junit4] 2> 615570 T2682 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:42426_je%2Fmw_awholynewcollection_0_shard2_replica3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 615571 T2654 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 615571 T2656 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000002 complete, response:{success={null={responseHeader={status=0,QTime=3021},core=awholynewcollection_0_shard1_replica1},null={responseHeader={status=0,QTime=3024},core=awholynewcollection_0_shard1_replica2},null={responseHeader={status=0,QTime=3032},core=awholynewcollection_0_shard2_replica1},null={responseHeader={status=0,QTime=3039},core=awholynewcollection_0_shard1_replica3},null={responseHeader={status=0,QTime=3046},core=awholynewcollection_0_shard2_replica2},null={responseHeader={status=0,QTime=3048},core=awholynewcollection_0_shard2_replica3}}}
[junit4:junit4] 2> 615573 T2709 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/collections params={numShards=2&maxShardsPerNode=2&name=awholynewcollection_0&replicationFactor=3&action=CREATE&wt=javabin&version=2} status=0 QTime=3058
[junit4:junit4] 2> 615575 T2632 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 615576 T2632 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 615577 T2750 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c7d6d4 name:ZooKeeperConnection Watcher:127.0.0.1:52762/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 615577 T2632 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 615578 T2632 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 615582 T2707 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&maxShardsPerNode=3&name=awholynewcollection_1&replicationFactor=5&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 615583 T2654 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 615584 T2656 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000004 message:{
[junit4:junit4] 2> "operation":"createcollection",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "maxShardsPerNode":"3",
[junit4:junit4] 2> "createNodeSet":null,
[junit4:junit4] 2> "name":"awholynewcollection_1",
[junit4:junit4] 2> "replicationFactor":"5"}
[junit4:junit4] 2> 615584 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard1_replica1 as part of slice shard1 of collection awholynewcollection_1 on 127.0.0.1:60580_je%2Fmw
[junit4:junit4] 2> 615585 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard1_replica2 as part of slice shard1 of collection awholynewcollection_1 on 127.0.0.1:44782_je%2Fmw
[junit4:junit4] 2> 615585 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard1_replica3 as part of slice shard1 of collection awholynewcollection_1 on 127.0.0.1:42426_je%2Fmw
[junit4:junit4] 2> 615585 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard1_replica4 as part of slice shard1 of collection awholynewcollection_1 on 127.0.0.1:42496_je%2Fmw
[junit4:junit4] 2> 615585 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard1_replica5 as part of slice shard1 of collection awholynewcollection_1 on 127.0.0.1:35800_je%2Fmw
[junit4:junit4] 2> 615585 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard2_replica1 as part of slice shard2 of collection awholynewcollection_1 on 127.0.0.1:60580_je%2Fmw
[junit4:junit4] 2> 615585 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard2_replica2 as part of slice shard2 of collection awholynewcollection_1 on 127.0.0.1:44782_je%2Fmw
[junit4:junit4] 2> 615586 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard2_replica3 as part of slice shard2 of collection awholynewcollection_1 on 127.0.0.1:42426_je%2Fmw
[junit4:junit4] 2> 615586 T2649 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_1_shard1_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/awholynewcollection_1_shard1_replica1
[junit4:junit4] 2> 615587 T2666 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_1_shard1_replica4' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370008659308/awholynewcollection_1_shard1_replica4
[junit4:junit4] 2> 615587 T2666 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 2> 615587 T2694 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_1_shard1_replica5' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370008661650/awholynewcollection_1_shard1_replica5
[junit4:junit4] 2> 615587 T2680 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_1_shard1_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370008660473/awholynewcollection_1_shard1_replica2
[junit4:junit4] 2> 615588 T2680 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 2> 615587 T2649 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 2> 615588 T2680 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_1
[junit4:junit4] 2> 615586 T2710 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_1_shard1_replica3' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370008662841/awholynewcollection_1_shard1_replica3
[junit4:junit4] 2> 615589 T2710 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 2> 615586 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard2_replica4 as part of slice shard2 of collection awholynewcollection_1 on 127.0.0.1:42496_je%2Fmw
[junit4:junit4] 2> 615586 T2647 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_1_shard2_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370008659116/awholynewcollection_1_shard2_replica1
[junit4:junit4] 2> 615589 T2647 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 2> 615589 T2656 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard2_replica5 as part of slice shard2 of collection awholynewcollection_1 on 127.0.0.1:35800_je%2Fmw
[junit4:junit4] 2> 615590 T2667 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_1_shard2_replica4' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty
[...truncated too long message...]
1> /solr/overseer_elect (2)
[junit4:junit4] 1> /solr/overseer_elect/election (5)
[junit4:junit4] 1> /solr/overseer_elect/election/89784887468294147-127.0.0.1:60580_je%2Fmw-n_0000000000 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89784887468294156-127.0.0.1:42426_je%2Fmw-n_0000000004 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89784887468294150-127.0.0.1:42496_je%2Fmw-n_0000000001 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89784887468294154-127.0.0.1:35800_je%2Fmw-n_0000000003 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89784887468294152-127.0.0.1:44782_je%2Fmw-n_0000000002 (0)
[junit4:junit4] 1> /solr/overseer_elect/leader (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"id":"89784887468294147-127.0.0.1:60580_je%2Fmw-n_0000000000"}
[junit4:junit4] 1> /zookeeper (1)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1>
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=BA96622C23C1655C -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en_US -Dtests.timezone=Pacific/Noumea -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] FAILURE 285s J0 | CollectionsAPIDistributedZkTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: java.lang.AssertionError: There are still nodes recoverying - waited for 230 seconds
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([BA96622C23C1655C:3B70EC34549E0560]:0)
[junit4:junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:173)
[junit4:junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131)
[junit4:junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:126)
[junit4:junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:512)
[junit4:junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:146)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:662)
[junit4:junit4] 2> 889522 T2632 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 285069 T2631 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4:junit4] 2> 890715 T2714 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/awholynewcollection_5/leader_elect/shard2/election
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4:junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:235)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:232)
[junit4:junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:232)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4] 2>
[junit4:junit4] 2> 890716 T2714 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/awholynewcollection_5/leader_elect/shard1/election
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4:junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:235)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:232)
[junit4:junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:232)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4] 2>
[junit4:junit4] 2> 890717 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 890717 T2714 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 890717 T2714 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {timestamp=Pulsing41(freqCutoff=13 minBlockSize=49 maxBlockSize=157), range_facet_l=Pulsing41(freqCutoff=13 minBlockSize=49 maxBlockSize=157), id=PostingsFormat(name=MockSep), range_facet_sl=PostingsFormat(name=Memory doPackFST= true), a_t=Pulsing41(freqCutoff=13 minBlockSize=49 maxBlockSize=157), text=PostingsFormat(name=Memory doPackFST= true), range_facet_si=MockFixedIntBlock(blockSize=646), _version_=Pulsing41(freqCutoff=13 minBlockSize=49 maxBlockSize=157), other_tl1=Pulsing41(freqCutoff=13 minBlockSize=49 maxBlockSize=157), multiDefault=MockFixedIntBlock(blockSize=646), a_si=MockFixedIntBlock(blockSize=646), intDefault=Pulsing41(freqCutoff=13 minBlockSize=49 maxBlockSize=157)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=en_US, timezone=Pacific/Noumea
[junit4:junit4] 2> NOTE: Linux 3.2.0-44-generic i386/Sun Microsystems Inc. 1.6.0_45 (32-bit)/cpus=8,threads=2,free=156378344,total=317063168
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestWriterPerf, SuggesterTest, RAMDirectoryFactoryTest, DistributedTermsComponentTest, SchemaVersionSpecificBehaviorTest, AnalysisAfterCoreReloadTest, TestPropInjectDefaults, TestSerializedLuceneMatchVersion, UpdateRequestProcessorFactoryTest, TestFastLRUCache, TestSchemaResource, DistributedSpellCheckComponentTest, TestPhraseSuggestions, ResponseLogComponentTest, BinaryUpdateRequestHandlerTest, IndexSchemaTest, TestLFUCache, ScriptEngineTest, TestSchemaVersionResource, TestSolrDeletionPolicy1, TestQuerySenderListener, PrimitiveFieldTypeTest, TestPseudoReturnFields, BasicDistributedZkTest, TestFuzzyAnalyzedSuggestions, SimpleFacetsTest, ClusterStateUpdateTest, TestStressVersions, TestRealTimeGet, MinimalSchemaTest, DistributedQueryElevationComponentTest, TestCollationKeyRangeQueries, TestLMDirichletSimilarityFactory, SliceStateUpdateTest, TestBadConfig, TestXIncludeConfig, LoggingHandlerTest, UUIDFieldTest, TestGroupingSearch, TestCharFilters, TestJoin, OverseerCollectionProcessorTest, QueryResultKeyTest, ZkControllerTest, FileBasedSpellCheckerTest, TestCloudManagedSchema, TestClassNameShortening, BadCopyFieldTest, AutoCommitTest, TestSweetSpotSimilarityFactory, DocumentBuilderTest, TestFastWriter, ReturnFieldsTest, SOLR749Test, PrimUtilsTest, SliceStateTest, SearchHandlerTest, UnloadDistributedZkTest, TestReplicationHandler, TestCoreContainer, TestFaceting, TestPerFieldSimilarity, TestReversedWildcardFilterFactory, SpellingQueryConverterTest, TestTrie, RecoveryZkTest, TestLRUCache, TestFieldTypeCollectionResource, TermsComponentTest, AlternateDirectoryTest, TestValueSourceCache, PolyFieldTest, BasicFunctionalityTest, CSVRequestHandlerTest, CollectionsAPIDistributedZkTest]
[junit4:junit4] Completed on J0 in 286.35s, 1 test, 1 failure <<< FAILURES!
[...truncated 450 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:386: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:366: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:437: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1243: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:887: There were test failures: 296 suites, 1235 tests, 1 failure, 13 ignored (7 assumptions)
Total time: 42 minutes 19 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.6.0_45 -server -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure