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/06/05 13:29:37 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.7.0_21) - Build # 5929
- Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/5929/
Java: 64bit/jdk1.7.0_21 -XX:-UseCompressedOops -XX:+UseSerialGC
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([D0C55A4E175D25A9:5123D45660024595]: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:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
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:722)
Build Log:
[...truncated 9720 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4:junit4] 2> 639379 T2238 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_sje/h
[junit4:junit4] 2> 639383 T2238 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-CollectionsAPIDistributedZkTest-1370431044317
[junit4:junit4] 2> 639384 T2238 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 639384 T2239 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 639484 T2238 oasc.ZkTestServer.run start zk server on port:43772
[junit4:junit4] 2> 639486 T2238 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 639490 T2245 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13d81554 name:ZooKeeperConnection Watcher:127.0.0.1:43772 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 639490 T2238 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 639491 T2238 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 639497 T2238 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 639499 T2247 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2d9ada14 name:ZooKeeperConnection Watcher:127.0.0.1:43772/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 639499 T2238 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 639500 T2238 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 639504 T2238 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 639508 T2238 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 639511 T2238 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 639514 T2238 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> 639515 T2238 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 639521 T2238 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> 639522 T2238 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 639526 T2238 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> 639527 T2238 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 639530 T2238 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> 639531 T2238 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 639534 T2238 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> 639535 T2238 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 639540 T2238 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> 639541 T2238 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 639544 T2238 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> 639545 T2238 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 639549 T2238 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> 639549 T2238 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 639552 T2238 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> 639553 T2238 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 639629 T2238 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 639632 T2238 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40521
[junit4:junit4] 2> 639633 T2238 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 639633 T2238 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 639633 T2238 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490
[junit4:junit4] 2> 639634 T2238 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/solr.xml
[junit4:junit4] 2> 639634 T2238 oasc.CoreContainer.<init> New CoreContainer 1419911500
[junit4:junit4] 2> 639634 T2238 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/'
[junit4:junit4] 2> 639635 T2238 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/'
[junit4:junit4] 2> 639678 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490
[junit4:junit4] 2> 639679 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/collection1
[junit4:junit4] 2> 639680 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/collection1/conf
[junit4:junit4] 2> 639686 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/collection1/conf/xslt
[junit4:junit4] 2> 639704 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/collection1/lib
[junit4:junit4] 2> 639705 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/collection1/lib/classes
[junit4:junit4] 2> 639707 T2238 oasc.SolrCoreDiscoverer.addCore Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/conf/core.properties, adding to cores
[junit4:junit4] 2> 639709 T2238 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 639709 T2238 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 639709 T2238 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 639710 T2238 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 639710 T2238 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 639710 T2238 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 639711 T2238 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 639711 T2238 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 639711 T2238 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 639712 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 639715 T2238 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 639715 T2238 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43772/solr
[junit4:junit4] 2> 639715 T2238 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 639716 T2238 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 639718 T2258 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7cdea7a2 name:ZooKeeperConnection Watcher:127.0.0.1:43772 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 639719 T2238 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 639721 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 639724 T2238 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 639726 T2260 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e3c5b9e name:ZooKeeperConnection Watcher:127.0.0.1:43772/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 639726 T2238 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 639728 T2238 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 639732 T2238 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 639735 T2238 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 639737 T2238 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40521__sje%2Fh
[junit4:junit4] 2> 639738 T2238 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40521__sje%2Fh
[junit4:junit4] 2> 639742 T2238 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 639749 T2238 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 639753 T2238 oasc.Overseer.start Overseer (id=89812568920489987-127.0.0.1:40521__sje%2Fh-n_0000000000) starting
[junit4:junit4] 2> 639757 T2238 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 639761 T2262 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 639762 T2238 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 639765 T2238 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 639767 T2238 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 639771 T2261 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 639774 T2238 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 639774 T2238 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 639775 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 639779 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 639781 T2238 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 639783 T2265 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e87b18d name:ZooKeeperConnection Watcher:127.0.0.1:43772/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 639783 T2238 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 639786 T2238 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 639789 T2238 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 639904 T2238 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 639906 T2238 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50648
[junit4:junit4] 2> 639907 T2238 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 639907 T2238 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 639908 T2238 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723
[junit4:junit4] 2> 639908 T2238 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/solr.xml
[junit4:junit4] 2> 639909 T2238 oasc.CoreContainer.<init> New CoreContainer 769636711
[junit4:junit4] 2> 639909 T2238 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/'
[junit4:junit4] 2> 639910 T2238 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/'
[junit4:junit4] 2> 639954 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723
[junit4:junit4] 2> 639955 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/collection1
[junit4:junit4] 2> 639955 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/collection1/conf
[junit4:junit4] 2> 639960 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/collection1/conf/xslt
[junit4:junit4] 2> 639976 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/collection1/lib
[junit4:junit4] 2> 639977 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/collection1/lib/classes
[junit4:junit4] 2> 639978 T2238 oasc.SolrCoreDiscoverer.addCore Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/conf/core.properties, adding to cores
[junit4:junit4] 2> 639980 T2238 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 639980 T2238 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 639981 T2238 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 639981 T2238 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 639981 T2238 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 639982 T2238 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 639982 T2238 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 639982 T2238 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 639983 T2238 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 639983 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 639986 T2238 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 639986 T2238 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43772/solr
[junit4:junit4] 2> 639987 T2238 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 639987 T2238 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 639989 T2276 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@48b7fff6 name:ZooKeeperConnection Watcher:127.0.0.1:43772 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 639990 T2238 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 639991 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 639994 T2238 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 639995 T2278 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@781ceee7 name:ZooKeeperConnection Watcher:127.0.0.1:43772/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 639996 T2238 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 639998 T2238 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 641000 T2238 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50648__sje%2Fh
[junit4:junit4] 2> 641001 T2238 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50648__sje%2Fh
[junit4:junit4] 2> 641004 T2260 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 641004 T2278 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 641004 T2265 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 641007 T2238 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 641008 T2238 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 641008 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 641072 T2238 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 641074 T2238 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55768
[junit4:junit4] 2> 641075 T2238 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 641075 T2238 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 641075 T2238 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943
[junit4:junit4] 2> 641076 T2238 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/solr.xml
[junit4:junit4] 2> 641076 T2238 oasc.CoreContainer.<init> New CoreContainer 1077095093
[junit4:junit4] 2> 641076 T2238 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/'
[junit4:junit4] 2> 641077 T2238 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/'
[junit4:junit4] 2> 641110 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943
[junit4:junit4] 2> 641111 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/collection1
[junit4:junit4] 2> 641111 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/collection1/conf
[junit4:junit4] 2> 641116 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/collection1/conf/xslt
[junit4:junit4] 2> 641131 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/collection1/lib
[junit4:junit4] 2> 641132 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/collection1/lib/classes
[junit4:junit4] 2> 641133 T2238 oasc.SolrCoreDiscoverer.addCore Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/conf/core.properties, adding to cores
[junit4:junit4] 2> 641134 T2238 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 641135 T2238 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 641135 T2238 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 641135 T2238 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 641136 T2238 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 641136 T2238 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 641136 T2238 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 641137 T2238 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 641137 T2238 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 641137 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 641140 T2238 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 641140 T2238 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43772/solr
[junit4:junit4] 2> 641141 T2238 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 641141 T2238 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 641143 T2290 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@68e3fd8f name:ZooKeeperConnection Watcher:127.0.0.1:43772 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 641143 T2238 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 641145 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 641148 T2238 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 641149 T2292 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7819441f name:ZooKeeperConnection Watcher:127.0.0.1:43772/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 641149 T2238 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 641152 T2238 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 642155 T2238 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55768__sje%2Fh
[junit4:junit4] 2> 642157 T2238 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55768__sje%2Fh
[junit4:junit4] 2> 642161 T2260 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 642161 T2292 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 642161 T2265 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 642161 T2278 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 642167 T2238 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 642168 T2238 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 642169 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 642254 T2238 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 642256 T2238 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53405
[junit4:junit4] 2> 642257 T2238 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 642257 T2238 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 642258 T2238 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106
[junit4:junit4] 2> 642259 T2238 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/solr.xml
[junit4:junit4] 2> 642259 T2238 oasc.CoreContainer.<init> New CoreContainer 1410395755
[junit4:junit4] 2> 642260 T2238 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/'
[junit4:junit4] 2> 642261 T2238 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/'
[junit4:junit4] 2> 642304 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106
[junit4:junit4] 2> 642305 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/collection1
[junit4:junit4] 2> 642305 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/collection1/conf
[junit4:junit4] 2> 642310 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/collection1/conf/xslt
[junit4:junit4] 2> 642325 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/collection1/lib
[junit4:junit4] 2> 642326 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/collection1/lib/classes
[junit4:junit4] 2> 642327 T2238 oasc.SolrCoreDiscoverer.addCore Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/conf/core.properties, adding to cores
[junit4:junit4] 2> 642329 T2238 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 642330 T2238 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 642330 T2238 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 642330 T2238 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 642330 T2238 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 642331 T2238 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 642331 T2238 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 642331 T2238 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 642332 T2238 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 642332 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 642335 T2238 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 642335 T2238 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43772/solr
[junit4:junit4] 2> 642336 T2238 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 642336 T2238 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 642338 T2304 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b089d39 name:ZooKeeperConnection Watcher:127.0.0.1:43772 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 642338 T2238 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 642340 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 642343 T2238 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 642344 T2306 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4d4014ca name:ZooKeeperConnection Watcher:127.0.0.1:43772/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 642344 T2238 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 642347 T2238 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 643349 T2238 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53405__sje%2Fh
[junit4:junit4] 2> 643351 T2238 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53405__sje%2Fh
[junit4:junit4] 2> 643355 T2260 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 643356 T2278 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 643356 T2306 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 643356 T2292 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 643356 T2265 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 643362 T2238 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 643363 T2238 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 643363 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 643440 T2238 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 643442 T2238 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50535
[junit4:junit4] 2> 643443 T2238 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 643443 T2238 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 643444 T2238 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302
[junit4:junit4] 2> 643444 T2238 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/solr.xml
[junit4:junit4] 2> 643445 T2238 oasc.CoreContainer.<init> New CoreContainer 1903425917
[junit4:junit4] 2> 643445 T2238 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/'
[junit4:junit4] 2> 643446 T2238 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/'
[junit4:junit4] 2> 643499 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302
[junit4:junit4] 2> 643500 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/collection1
[junit4:junit4] 2> 643500 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/collection1/conf
[junit4:junit4] 2> 643505 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/collection1/conf/xslt
[junit4:junit4] 2> 643522 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/collection1/lib
[junit4:junit4] 2> 643523 T2238 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/collection1/lib/classes
[junit4:junit4] 2> 643524 T2238 oasc.SolrCoreDiscoverer.addCore Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/conf/core.properties, adding to cores
[junit4:junit4] 2> 643526 T2238 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 643527 T2238 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 643527 T2238 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 643527 T2238 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 643528 T2238 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 643528 T2238 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 643528 T2238 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 643529 T2238 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 643529 T2238 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 643529 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 643533 T2238 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 643533 T2238 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43772/solr
[junit4:junit4] 2> 643533 T2238 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 643534 T2238 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 643536 T2318 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55d7adc4 name:ZooKeeperConnection Watcher:127.0.0.1:43772 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 643536 T2238 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 643538 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 643541 T2238 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 643542 T2320 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2de7ab1c name:ZooKeeperConnection Watcher:127.0.0.1:43772/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 643542 T2238 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 643545 T2238 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 644548 T2238 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50535__sje%2Fh
[junit4:junit4] 2> 644551 T2238 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50535__sje%2Fh
[junit4:junit4] 2> 644556 T2306 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 644556 T2265 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 644556 T2278 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 644556 T2260 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 644556 T2292 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 644557 T2320 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 644564 T2238 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 644565 T2238 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 644565 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 644573 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 644582 T2272 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 644584 T2260 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 644586 T2262 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> 644586 T2262 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:50648__sje%2Fh
[junit4:junit4] 2> 644587 T2262 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:40521__sje%2Fh
[junit4:junit4] 2> 644588 T2262 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:53405__sje%2Fh
[junit4:junit4] 2> 644589 T2262 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:50535__sje%2Fh
[junit4:junit4] 2> 644590 T2273 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 644590 T2256 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 644591 T2273 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 644592 T2316 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 644593 T2316 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 644592 T2301 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 644594 T2301 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 644592 T2256 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 644594 T2316 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 644595 T2256 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 644593 T2273 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 644596 T2256 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 644595 T2316 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 644595 T2301 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 644598 T2256 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 644597 T2273 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 644599 T2256 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 644599 T2316 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 644598 T2301 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 644600 T2273 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 644600 T2316 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 644601 T2273 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 644602 T2301 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 644602 T2256 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 644604 T2316 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 644605 T2301 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 644605 T2273 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 644606 T2316 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/nodes_used_collection_shard2_replica2/'
[junit4:junit4] 2> 644606 T2256 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/nodes_used_collection_shard1_replica2/'
[junit4:junit4] 2> 644608 T2273 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/nodes_used_collection_shard1_replica1/'
[junit4:junit4] 2> 644607 T2301 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/nodes_used_collection_shard2_replica1/'
[junit4:junit4] 2> 644678 T2316 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 644679 T2301 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 644682 T2256 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 644684 T2273 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 644734 T2301 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 644735 T2256 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 644736 T2301 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 644736 T2316 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 644736 T2256 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 644737 T2316 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 644737 T2273 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 644738 T2273 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 644740 T2316 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica2] Schema name=test
[junit4:junit4] 2> 644741 T2301 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica1] Schema name=test
[junit4:junit4] 2> 644741 T2256 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica2] Schema name=test
[junit4:junit4] 2> 644741 T2273 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica1] Schema name=test
[junit4:junit4] 2> 645260 T2316 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 645264 T2256 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 645278 T2316 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 645281 T2256 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 645282 T2316 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 645286 T2256 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 645298 T2316 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 645300 T2256 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 645301 T2316 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 645303 T2256 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 645304 T2316 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 645305 T2273 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 645305 T2316 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 645305 T2316 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 645306 T2316 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 645306 T2301 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 645306 T2256 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 645307 T2316 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 645307 T2316 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 645307 T2256 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 645309 T2256 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 645307 T2316 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 645309 T2256 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 645309 T2316 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/nodes_used_collection_shard2_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/nodes_used_collection_shard2_replica2/data/
[junit4:junit4] 2> 645310 T2316 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@fb51005
[junit4:junit4] 2> 645310 T2256 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 645310 T2256 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 645310 T2316 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 645311 T2256 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 645310 T2273 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 645311 T2301 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 645311 T2316 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/nodes_used_collection_shard2_replica2/data
[junit4:junit4] 2> 645311 T2256 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/nodes_used_collection_shard1_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/nodes_used_collection_shard1_replica2/data/
[junit4:junit4] 2> 645312 T2316 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/nodes_used_collection_shard2_replica2/data/index/
[junit4:junit4] 2> 645312 T2256 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@fb51005
[junit4:junit4] 2> 645313 T2316 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/nodes_used_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 645313 T2256 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 645314 T2273 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 645313 T2316 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/nodes_used_collection_shard2_replica2/data/index
[junit4:junit4] 2> 645314 T2256 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/nodes_used_collection_shard1_replica2/data
[junit4:junit4] 2> 645314 T2256 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/nodes_used_collection_shard1_replica2/data/index/
[junit4:junit4] 2> 645315 T2256 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/nodes_used_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 645314 T2301 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 645315 T2256 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/nodes_used_collection_shard1_replica2/data/index
[junit4:junit4] 2> 645316 T2316 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69dcdc3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5d674728),segFN=segments_1,generation=1}
[junit4:junit4] 2> 645316 T2316 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 645318 T2256 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@70c91f5a lockFactory=org.apache.lucene.store.NativeFSLockFactory@3a1abaa6),segFN=segments_1,generation=1}
[junit4:junit4] 2> 645318 T2256 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 645319 T2316 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 645326 T2316 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 645327 T2316 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 645327 T2256 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 645328 T2316 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 645328 T2256 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 645328 T2316 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 645329 T2316 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 645329 T2256 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 645329 T2316 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 645329 T2256 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 645330 T2316 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 645330 T2256 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 645330 T2316 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 645330 T2256 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 645331 T2273 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 645331 T2256 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 645332 T2301 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 645332 T2256 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 645332 T2256 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 645334 T2316 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 645334 T2256 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 645335 T2301 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 645335 T2273 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 645337 T2256 oass.SolrIndexSearcher.<init> Opening Searcher@3044237c main
[junit4:junit4] 2> 645337 T2316 oass.SolrIndexSearcher.<init> Opening Searcher@3044237c main
[junit4:junit4] 2> 645337 T2256 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/nodes_used_collection_shard1_replica2/data/tlog
[junit4:junit4] 2> 645337 T2316 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/nodes_used_collection_shard2_replica2/data/tlog
[junit4:junit4] 2> 645338 T2256 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 645338 T2316 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 645338 T2273 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 645338 T2301 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 645339 T2316 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 645338 T2256 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 645340 T2301 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 645340 T2301 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 645340 T2273 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 645341 T2301 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 645341 T2273 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 645342 T2273 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 645342 T2301 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 645342 T2301 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 645343 T2301 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 645343 T2326 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@3044237c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 645343 T2273 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 645343 T2273 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 645343 T2327 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@3044237c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 645344 T2273 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 645344 T2256 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=down
[junit4:junit4] 2> 645343 T2301 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/nodes_used_collection_shard2_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/nodes_used_collection_shard2_replica1/data/
[junit4:junit4] 2> 645344 T2273 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/nodes_used_collection_shard1_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/nodes_used_collection_shard1_replica1/data/
[junit4:junit4] 2> 645345 T2301 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@fb51005
[junit4:junit4] 2> 645345 T2273 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@fb51005
[junit4:junit4] 2> 645345 T2316 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=down
[junit4:junit4] 2> 645346 T2273 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 645346 T2301 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 645347 T2273 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/nodes_used_collection_shard1_replica1/data
[junit4:junit4] 2> 645347 T2273 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/nodes_used_collection_shard1_replica1/data/index/
[junit4:junit4] 2> 645347 T2301 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/nodes_used_collection_shard2_replica1/data
[junit4:junit4] 2> 645347 T2273 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/nodes_used_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 645347 T2301 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/nodes_used_collection_shard2_replica1/data/index/
[junit4:junit4] 2> 645348 T2273 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/nodes_used_collection_shard1_replica1/data/index
[junit4:junit4] 2> 645348 T2301 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/nodes_used_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 645349 T2301 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/nodes_used_collection_shard2_replica1/data/index
[junit4:junit4] 2> 645349 T2273 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2938a58c lockFactory=org.apache.lucene.store.NativeFSLockFactory@7678067b),segFN=segments_1,generation=1}
[junit4:junit4] 2> 645350 T2273 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 645350 T2301 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@62dd3fd2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1e3dfeb2),segFN=segments_1,generation=1}
[junit4:junit4] 2> 645350 T2301 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 645352 T2273 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 645352 T2301 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 645352 T2273 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 645352 T2301 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 645353 T2273 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 645353 T2301 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 645353 T2273 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 645353 T2301 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 645354 T2273 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 645354 T2273 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 645354 T2301 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 645354 T2273 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 645354 T2301 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 645355 T2273 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 645355 T2301 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 645355 T2273 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 645356 T2301 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 645356 T2301 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 645358 T2273 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 645358 T2301 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 645360 T2301 oass.SolrIndexSearcher.<init> Opening Searcher@5599be0d main
[junit4:junit4] 2> 645360 T2273 oass.SolrIndexSearcher.<init> Opening Searcher@56fbf8f4 main
[junit4:junit4] 2> 645361 T2301 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/nodes_used_collection_shard2_replica1/data/tlog
[junit4:junit4] 2> 645361 T2273 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/nodes_used_collection_shard1_replica1/data/tlog
[junit4:junit4] 2> 645361 T2301 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 645362 T2273 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 645362 T2301 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 645362 T2273 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 645365 T2328 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@5599be0d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 645365 T2329 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@56fbf8f4 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 645365 T2301 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=down
[junit4:junit4] 2> 645366 T2273 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=down
[junit4:junit4] 2> 645782 T2261 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 645783 T2261 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:40521__sje%2Fh",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:40521/_sje/h"}
[junit4:junit4] 2> 645784 T2261 oasc.Overseer$ClusterStateUpdater.createCollection Create collection nodes_used_collection with numShards 2
[junit4:junit4] 2> 645787 T2261 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:50535__sje%2Fh",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50535/_sje/h"}
[junit4:junit4] 2> 645791 T2261 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:53405__sje%2Fh",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53405/_sje/h"}
[junit4:junit4] 2> 645794 T2261 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:50648__sje%2Fh",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50648/_sje/h"}
[junit4:junit4] 2> 645800 T2260 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> 645800 T2278 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> 645800 T2292 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> 645800 T2265 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> 645800 T2306 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> 645800 T2320 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> 646346 T2256 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 646347 T2256 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica2 address:http://127.0.0.1:40521/_sje/h collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 646347 T2316 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 646348 T2316 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica2 address:http://127.0.0.1:50535/_sje/h collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 646348 T2256 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4:junit4] 2> 646349 T2316 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4:junit4] 2> 646359 T2256 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 646360 T2316 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 646363 T2256 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179999
[junit4:junit4] 2> 646363 T2316 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=180000
[junit4:junit4] 2> 646367 T2301 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 646367 T2301 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:53405/_sje/h collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 646367 T2273 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 646368 T2273 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica1 address:http://127.0.0.1:50648/_sje/h collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 646864 T2256 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 646865 T2316 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 646866 T2316 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 646865 T2256 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 646866 T2316 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50535/_sje/h/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 646867 T2256 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:40521/_sje/h/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 646867 T2316 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:50535/_sje/h START replicas=[http://127.0.0.1:53405/_sje/h/nodes_used_collection_shard2_replica1/] nUpdates=100
[junit4:junit4] 2> 646868 T2256 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:40521/_sje/h START replicas=[http://127.0.0.1:50648/_sje/h/nodes_used_collection_shard1_replica1/] nUpdates=100
[junit4:junit4] 2> 646869 T2316 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:50535/_sje/h DONE. We have no versions. sync failed.
[junit4:junit4] 2> 646870 T2316 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 646870 T2316 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> 646871 T2316 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50535/_sje/h/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 646872 T2316 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard2
[junit4:junit4] 2> 646869 T2256 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:40521/_sje/h DONE. We have no versions. sync failed.
[junit4:junit4] 2> 646873 T2256 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 646874 T2256 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> 646874 T2256 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:40521/_sje/h/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 646875 T2256 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard1
[junit4:junit4] 2> ASYNC NEW_CORE C2140 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@7e6287ef url=http://127.0.0.1:50648/_sje/h/nodes_used_collection_shard1_replica1 node=127.0.0.1:50648__sje%2Fh C2140_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica1 props:{shard=shard1, state=down, core=nodes_used_collection_shard1_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50648__sje%2Fh, base_url=http://127.0.0.1:50648/_sje/h}
[junit4:junit4] 2> 646880 T2271 C2140 P50648 oasc.SolrCore.execute [nodes_used_collection_shard1_replica1] webapp=/_sje/h path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=2
[junit4:junit4] 2> ASYNC NEW_CORE C2141 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@64c01405 url=http://127.0.0.1:53405/_sje/h/nodes_used_collection_shard2_replica1 node=127.0.0.1:53405__sje%2Fh C2141_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=down, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:53405__sje%2Fh, base_url=http://127.0.0.1:53405/_sje/h}
[junit4:junit4] 2> 646881 T2300 C2141 P53405 oasc.SolrCore.execute [nodes_used_collection_shard2_replica1] webapp=/_sje/h path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 647312 T2261 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 647333 T2260 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> 647333 T2278 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> 647333 T2265 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> 647333 T2292 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> 647333 T2306 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> 647333 T2320 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> 647373 T2301 oasc.ZkController.register We are http://127.0.0.1:53405/_sje/h/nodes_used_collection_shard2_replica1/ and leader is http://127.0.0.1:50535/_sje/h/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 647373 T2273 oasc.ZkController.register We are http://127.0.0.1:50648/_sje/h/nodes_used_collection_shard1_replica1/ and leader is http://127.0.0.1:40521/_sje/h/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 647373 T2301 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica1 baseURL=http://127.0.0.1:53405/_sje/h
[junit4:junit4] 2> 647374 T2301 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 647375 T2301 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 647374 T2273 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica1 baseURL=http://127.0.0.1:50648/_sje/h
[junit4:junit4] 2> 647376 T2273 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 647377 T2273 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 647376 T2332 C2141 P53405 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard2_replica1 recoveringAfterStartup=true
[junit4:junit4] 2> 647377 T2333 C2140 P50648 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard1_replica1 recoveringAfterStartup=true
[junit4:junit4] 2> 647376 T2301 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 647378 T2333 C2140 P50648 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 647378 T2273 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 647380 T2301 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=2788
[junit4:junit4] 2> 647378 T2332 C2141 P53405 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 647381 T2273 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=2791
[junit4:junit4] 2> 647382 T2332 C2141 P53405 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=recovering
[junit4:junit4] 2> 647380 T2333 C2140 P50648 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=recovering
[junit4:junit4] 2> 647383 T2316 oasc.ZkController.register We are http://127.0.0.1:50535/_sje/h/nodes_used_collection_shard2_replica2/ and leader is http://127.0.0.1:50535/_sje/h/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 647384 T2332 C2141 P53405 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 647384 T2333 C2140 P50648 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 647384 T2316 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica2 baseURL=http://127.0.0.1:50535/_sje/h
[junit4:junit4] 2> 647385 T2316 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 647385 T2256 oasc.ZkController.register We are http://127.0.0.1:40521/_sje/h/nodes_used_collection_shard1_replica2/ and leader is http://127.0.0.1:40521/_sje/h/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 647386 T2316 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=active
[junit4:junit4] 2> 647386 T2256 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica2 baseURL=http://127.0.0.1:40521/_sje/h
[junit4:junit4] 2> 647387 T2256 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 647388 T2256 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=active
[junit4:junit4] 2> 647388 T2316 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 647390 T2316 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=2798
[junit4:junit4] 2> 647390 T2256 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 647391 T2256 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=2801
[junit4:junit4] 2> 647392 T2262 oasc.OverseerCollectionProcessor.createCollection Finished create command on all shards for collection: nodes_used_collection
[junit4:junit4] 2> 647395 T2255 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:50648__sje%2Fh_nodes_used_collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 647395 T2315 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:53405__sje%2Fh_nodes_used_collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 647416 T2278 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work/qnr-0000000000 state: SyncConnected type NodeDataChanged
[junit4:junit4] 2> 647417 T2260 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 647417 T2262 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000000 complete, response:{success={null={responseHeader={status=0,QTime=2788},core=nodes_used_collection_shard2_replica1},null={responseHeader={status=0,QTime=2791},core=nodes_used_collection_shard1_replica1},null={responseHeader={status=0,QTime=2798},core=nodes_used_collection_shard2_replica2},null={responseHeader={status=0,QTime=2801},core=nodes_used_collection_shard1_replica2}}}
[junit4:junit4] 2> 647422 T2272 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=2843
[junit4:junit4] 2> 647424 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 647425 T2238 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 647427 T2335 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7de85bd2 name:ZooKeeperConnection Watcher:127.0.0.1:43772/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 647428 T2238 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 647430 T2238 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 647434 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 647436 T2238 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 647438 T2337 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@170711d1 name:ZooKeeperConnection Watcher:127.0.0.1:43772/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 647438 T2238 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 647440 T2238 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 647448 T2314 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&maxShardsPerNode=1&name=awholynewcollection_0&replicationFactor=2&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 647450 T2260 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 647452 T2262 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":"1",
[junit4:junit4] 2> "createNodeSet":null,
[junit4:junit4] 2> "name":"awholynewcollection_0",
[junit4:junit4] 2> "replicationFactor":"2"}
[junit4:junit4] 2> 647452 T2262 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica1 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:40521__sje%2Fh
[junit4:junit4] 2> 647453 T2262 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica2 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:55768__sje%2Fh
[junit4:junit4] 2> 647453 T2262 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica1 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:50535__sje%2Fh
[junit4:junit4] 2> 647453 T2262 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica2 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:53405__sje%2Fh
[junit4:junit4] 2> 647455 T2256 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/awholynewcollection_0_shard1_replica1
[junit4:junit4] 2> 647456 T2316 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/awholynewcollection_0_shard2_replica1
[junit4:junit4] 2> 647456 T2316 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 647456 T2300 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/awholynewcollection_0_shard2_replica2
[junit4:junit4] 2> 647456 T2256 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 647455 T2285 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/awholynewcollection_0_shard1_replica2
[junit4:junit4] 2> 647457 T2316 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 647457 T2300 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 647457 T2316 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 647458 T2300 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 647457 T2256 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 647457 T2285 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 647459 T2256 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 647458 T2316 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 647458 T2300 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 647459 T2316 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 647459 T2285 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 647460 T2285 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 647459 T2256 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 647460 T2300 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 647461 T2256 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 647462 T2285 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 647461 T2300 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 647462 T2316 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 647463 T2256 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 647464 T2285 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 647464 T2300 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 647465 T2256 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/awholynewcollection_0_shard1_replica1/'
[junit4:junit4] 2> 647465 T2316 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/awholynewcollection_0_shard2_replica1/'
[junit4:junit4] 2> 647466 T2300 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/awholynewcollection_0_shard2_replica2/'
[junit4:junit4] 2> 647468 T2285 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/awholynewcollection_0_shard1_replica2/'
[junit4:junit4] 2> 647509 T2256 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 647516 T2316 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 647533 T2300 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 647534 T2285 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 647561 T2256 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 647563 T2256 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 647568 T2256 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica1] Schema name=test
[junit4:junit4] 2> 647590 T2316 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 647591 T2285 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 647592 T2316 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 647592 T2285 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 647595 T2300 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 647596 T2285 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica2] Schema name=test
[junit4:junit4] 2> 647596 T2316 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica1] Schema name=test
[junit4:junit4] 2> 647596 T2300 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 647602 T2300 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica2] Schema name=test
[junit4:junit4] 2> 648125 T2256 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 648130 T2256 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 648132 T2256 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 648143 T2256 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 648144 T2285 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 648153 T2256 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 648156 T2256 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 648157 T2256 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 648158 T2256 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 648157 T2285 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 648158 T2256 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 648159 T2256 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 648159 T2256 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 648160 T2256 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 648160 T2256 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/awholynewcollection_0_shard1_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/awholynewcollection_0_shard1_replica1/data/
[junit4:junit4] 2> 648160 T2256 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@fb51005
[junit4:junit4] 2> 648161 T2256 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 648161 T2256 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/awholynewcollection_0_shard1_replica1/data
[junit4:junit4] 2> 648161 T2285 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 648161 T2256 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/awholynewcollection_0_shard1_replica1/data/index/
[junit4:junit4] 2> 648162 T2256 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/awholynewcollection_0_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 648163 T2256 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/awholynewcollection_0_shard1_replica1/data/index
[junit4:junit4] 2> 648164 T2256 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5f558235 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7ee2e991),segFN=segments_1,generation=1}
[junit4:junit4] 2> 648165 T2256 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 648166 T2256 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 648167 T2256 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 648168 T2256 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 648168 T2256 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 648169 T2256 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 648169 T2256 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 648169 T2256 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 648170 T2256 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 648170 T2256 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 648173 T2256 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 648173 T2285 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 648175 T2256 oass.SolrIndexSearcher.<init> Opening Searcher@761562dc main
[junit4:junit4] 2> 648175 T2256 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/awholynewcollection_0_shard1_replica1/data/tlog
[junit4:junit4] 2> 648176 T2256 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 648176 T2256 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 648178 T2316 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 648179 T2338 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard1_replica1] Registered new searcher Searcher@761562dc main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 648179 T2285 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 648180 T2256 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica1 state=down
[junit4:junit4] 2> 648183 T2285 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 648192 T2316 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 648193 T2285 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 648193 T2285 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 648194 T2285 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 648194 T2285 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 648195 T2285 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 648195 T2316 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 648195 T2285 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 648195 T2285 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/awholynewcollection_0_shard1_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/awholynewcollection_0_shard1_replica2/data/
[junit4:junit4] 2> 648196 T2285 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@fb51005
[junit4:junit4] 2> 648196 T2285 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 648197 T2285 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/awholynewcollection_0_shard1_replica2/data
[junit4:junit4] 2> 648197 T2285 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/awholynewcollection_0_shard1_replica2/data/index/
[junit4:junit4] 2> 648197 T2285 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/awholynewcollection_0_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 648198 T2285 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/awholynewcollection_0_shard1_replica2/data/index
[junit4:junit4] 2> 648199 T2285 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7be66c9a lockFactory=org.apache.lucene.store.NativeFSLockFactory@16fe22bd),segFN=segments_1,generation=1}
[junit4:junit4] 2> 648200 T2285 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 648202 T2285 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 648202 T2285 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 648202 T2285 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 648203 T2285 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 648203 T2316 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 648203 T2285 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 648204 T2285 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 648204 T2285 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 648204 T2285 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 648205 T2285 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 648206 T2300 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 648208 T2316 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 648209 T2285 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 648210 T2316 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 648211 T2316 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 648211 T2316 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 648211 T2300 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 648212 T2316 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 648212 T2285 oass.SolrIndexSearcher.<init> Opening Searcher@7247adec main
[junit4:junit4] 2> 648213 T2316 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 648213 T2316 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 648213 T2285 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/awholynewcollection_0_shard1_replica2/data/tlog
[junit4:junit4] 2> 648213 T2316 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 648214 T2316 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/awholynewcollection_0_shard2_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/awholynewcollection_0_shard2_replica1/data/
[junit4:junit4] 2> 648214 T2300 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 648214 T2285 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 648214 T2316 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@fb51005
[junit4:junit4] 2> 648215 T2285 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 648215 T2316 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 648216 T2316 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/awholynewcollection_0_shard2_replica1/data
[junit4:junit4] 2> 648216 T2316 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/awholynewcollection_0_shard2_replica1/data/index/
[junit4:junit4] 2> 648217 T2316 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/awholynewcollection_0_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 648217 T2316 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/awholynewcollection_0_shard2_replica1/data/index
[junit4:junit4] 2> 648219 T2339 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard1_replica2] Registered new searcher Searcher@7247adec main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 648219 T2316 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4893dc92 lockFactory=org.apache.lucene.store.NativeFSLockFactory@bd1a97),segFN=segments_1,generation=1}
[junit4:junit4] 2> 648219 T2316 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 648220 T2285 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica2 state=down
[junit4:junit4] 2> 648221 T2316 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 648222 T2316 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 648222 T2316 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 648223 T2316 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 648224 T2316 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 648224 T2316 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 648224 T2316 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 648225 T2300 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 648225 T2316 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 648225 T2316 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 648228 T2316 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 648229 T2300 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 648230 T2316 oass.SolrIndexSearcher.<init> Opening Searcher@3cf48fb3 main
[junit4:junit4] 2> 648230 T2316 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/awholynewcollection_0_shard2_replica1/data/tlog
[junit4:junit4] 2> 648231 T2316 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 648231 T2316 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 648232 T2300 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 648233 T2300 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 648233 T2300 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 648233 T2300 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 648234 T2340 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard2_replica1] Registered new searcher Searcher@3cf48fb3 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 648234 T2300 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 648235 T2300 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 648235 T2300 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 648235 T2316 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica1 state=down
[junit4:junit4] 2> 648235 T2300 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/awholynewcollection_0_shard2_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/awholynewcollection_0_shard2_replica2/data/
[junit4:junit4] 2> 648236 T2300 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@fb51005
[junit4:junit4] 2> 648236 T2300 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 648237 T2300 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/awholynewcollection_0_shard2_replica2/data
[junit4:junit4] 2> 648237 T2300 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/awholynewcollection_0_shard2_replica2/data/index/
[junit4:junit4] 2> 648237 T2300 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/awholynewcollection_0_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 648238 T2300 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/awholynewcollection_0_shard2_replica2/data/index
[junit4:junit4] 2> 648239 T2300 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@74747892 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4018c1f6),segFN=segments_1,generation=1}
[junit4:junit4] 2> 648240 T2300 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 648242 T2300 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 648242 T2300 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 648243 T2300 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 648244 T2300 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 648244 T2300 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 648244 T2300 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 648245 T2300 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 648246 T2300 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 648246 T2300 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 648249 T2300 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 648252 T2300 oass.SolrIndexSearcher.<init> Opening Searcher@655ded5d main
[junit4:junit4] 2> 648252 T2300 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/awholynewcollection_0_shard2_replica2/data/tlog
[junit4:junit4] 2> 648253 T2300 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 648253 T2300 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 648256 T2341 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard2_replica2] Registered new searcher Searcher@655ded5d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 648257 T2300 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica2 state=down
[junit4:junit4] 2> 648845 T2261 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 648846 T2261 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:53405__sje%2Fh_nodes_used_collection_shard2_replica1",
[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_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53405__sje%2Fh",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53405/_sje/h"}
[junit4:junit4] 2> 648851 T2261 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50648__sje%2Fh_nodes_used_collection_shard1_replica1",
[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_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50648__sje%2Fh",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50648/_sje/h"}
[junit4:junit4] 2> 648856 T2261 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50535__sje%2Fh_nodes_used_collection_shard2_replica2",
[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_replica2",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50535__sje%2Fh",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50535/_sje/h"}
[junit4:junit4] 2> 648861 T2261 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:40521__sje%2Fh_nodes_used_collection_shard1_replica2",
[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_replica2",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:40521__sje%2Fh",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:40521/_sje/h"}
[junit4:junit4] 2> 648865 T2261 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:40521__sje%2Fh",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:40521/_sje/h"}
[junit4:junit4] 2> 648866 T2261 oasc.Overseer$ClusterStateUpdater.createCollection Create collection awholynewcollection_0 with numShards 2
[junit4:junit4] 2> 648870 T2261 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:55768__sje%2Fh",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55768/_sje/h"}
[junit4:junit4] 2> 648874 T2261 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:50535__sje%2Fh",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50535/_sje/h"}
[junit4:junit4] 2> 648879 T2261 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:53405__sje%2Fh",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53405/_sje/h"}
[junit4:junit4] 2> 648883 T2260 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> 648883 T2306 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> 648884 T2265 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> 648883 T2320 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> 648884 T2278 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> 648883 T2337 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> 648883 T2335 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> 648883 T2292 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> 649182 T2256 oasc.CoreContainer.registerCore registering core: awholynewcollection_0_shard1_replica1
[junit4:junit4] 2> 649182 T2256 oasc.ZkController.register Register replica - core:awholynewcollection_0_shard1_replica1 address:http://127.0.0.1:40521/_sje/h collection:awholynewcollection_0 shard:shard1
[junit4:junit4] 2> 649184 T2256 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0/leader_elect/shard1/election
[junit4:junit4] 2> 649194 T2256 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 649198 T2256 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179999
[junit4:junit4] 2> 649221 T2285 oasc.CoreContainer.registerCore registering core: awholynewcollection_0_shard1_replica2
[junit4:junit4] 2> 649222 T2285 oasc.ZkController.register Register replica - core:awholynewcollection_0_shard1_replica2 address:http://127.0.0.1:55768/_sje/h collection:awholynewcollection_0 shard:shard1
[junit4:junit4] 2> 649236 T2316 oasc.CoreContainer.registerCore registering core: awholynewcollection_0_shard2_replica1
[junit4:junit4] 2> 649237 T2316 oasc.ZkController.register Register replica - core:awholynewcollection_0_shard2_replica1 address:http://127.0.0.1:50535/_sje/h collection:awholynewcollection_0 shard:shard2
[junit4:junit4] 2> 649238 T2316 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0/leader_elect/shard2/election
[junit4:junit4] 2> 649248 T2316 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 649252 T2316 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179999
[junit4:junit4] 2> 649259 T2300 oasc.CoreContainer.registerCore registering core: awholynewcollection_0_shard2_replica2
[junit4:junit4] 2> 649259 T2300 oasc.ZkController.register Register replica - core:awholynewcollection_0_shard2_replica2 address:http://127.0.0.1:53405/_sje/h collection:awholynewcollection_0 shard:shard2
[junit4:junit4] 2> 649396 T2255 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:50648__sje%2Fh_nodes_used_collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 649396 T2315 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:53405__sje%2Fh_nodes_used_collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 649397 T2315 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:53405__sje%252Fh_nodes_used_collection_shard2_replica1&state=recovering&nodeName=127.0.0.1:53405__sje%252Fh&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard2_replica2&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2002
[junit4:junit4] 2> 649397 T2255 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:50648__sje%252Fh_nodes_used_collection_shard1_replica1&state=recovering&nodeName=127.0.0.1:50648__sje%252Fh&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard1_replica2&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2002
[junit4:junit4] 2> 649699 T2256 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 649700 T2256 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 649700 T2256 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:40521/_sje/h/awholynewcollection_0_shard1_replica1/
[junit4:junit4] 2> 649700 T2256 oasu.PeerSync.sync PeerSync: core=awholynewcollection_0_shard1_replica1 url=http://127.0.0.1:40521/_sje/h START replicas=[http://127.0.0.1:55768/_sje/h/awholynewcollection_0_shard1_replica2/] nUpdates=100
[junit4:junit4] 2> 649701 T2256 oasu.PeerSync.sync PeerSync: core=awholynewcollection_0_shard1_replica1 url=http://127.0.0.1:40521/_sje/h DONE. We have no versions. sync failed.
[junit4:junit4] 2> 649701 T2256 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 649701 T2256 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> 649701 T2256 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:40521/_sje/h/awholynewcollection_0_shard1_replica1/
[junit4:junit4] 2> 649702 T2256 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0/leaders/shard1
[junit4:junit4] 2> ASYNC NEW_CORE C2142 name=awholynewcollection_0_shard1_replica2 org.apache.solr.core.SolrCore@63c9fa33 url=http://127.0.0.1:55768/_sje/h/awholynewcollection_0_shard1_replica2 node=127.0.0.1:55768__sje%2Fh C2142_STATE=coll:awholynewcollection_0 core:awholynewcollection_0_shard1_replica2 props:{shard=shard1, state=down, core=awholynewcollection_0_shard1_replica2, collection=awholynewcollection_0, node_name=127.0.0.1:55768__sje%2Fh, base_url=http://127.0.0.1:55768/_sje/h}
[junit4:junit4] 2> 649708 T2288 C2142 P55768 oasc.SolrCore.execute [awholynewcollection_0_shard1_replica2] webapp=/_sje/h path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 649753 T2316 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 649753 T2316 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 649753 T2316 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50535/_sje/h/awholynewcollection_0_shard2_replica1/
[junit4:junit4] 2> 649754 T2316 oasu.PeerSync.sync PeerSync: core=awholynewcollection_0_shard2_replica1 url=http://127.0.0.1:50535/_sje/h START replicas=[http://127.0.0.1:53405/_sje/h/awholynewcollection_0_shard2_replica2/] nUpdates=100
[junit4:junit4] 2> 649754 T2316 oasu.PeerSync.sync PeerSync: core=awholynewcollection_0_shard2_replica1 url=http://127.0.0.1:50535/_sje/h DONE. We have no versions. sync failed.
[junit4:junit4] 2> 649754 T2316 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 649755 T2316 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> 649755 T2316 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50535/_sje/h/awholynewcollection_0_shard2_replica1/
[junit4:junit4] 2> 649755 T2316 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0/leaders/shard2
[junit4:junit4] 2> ASYNC NEW_CORE C2143 name=awholynewcollection_0_shard2_replica2 org.apache.solr.core.SolrCore@6a344171 url=http://127.0.0.1:53405/_sje/h/awholynewcollection_0_shard2_replica2 node=127.0.0.1:53405__sje%2Fh C2143_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:53405__sje%2Fh, base_url=http://127.0.0.1:53405/_sje/h}
[junit4:junit4] 2> 649762 T2299 C2143 P53405 oasc.SolrCore.execute [awholynewcollection_0_shard2_replica2] webapp=/_sje/h path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 650404 T2261 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 650424 T2260 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> 650424 T2335 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> 650425 T2278 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> 650424 T2265 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> 650424 T2320 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> 650424 T2337 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> 650424 T2306 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> 650424 T2292 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> 650458 T2256 oasc.ZkController.register We are http://127.0.0.1:40521/_sje/h/awholynewcollection_0_shard1_replica1/ and leader is http://127.0.0.1:40521/_sje/h/awholynewcollection_0_shard1_replica1/
[junit4:junit4] 2> 650459 T2256 oasc.ZkController.register No LogReplay needed for core=awholynewcollection_0_shard1_replica1 baseURL=http://127.0.0.1:40521/_sje/h
[junit4:junit4] 2> 650459 T2256 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 650460 T2256 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica1 state=active
[junit4:junit4] 2> 650461 T2316 oasc.ZkController.register We are http://127.0.0.1:50535/_sje/h/awholynewcollection_0_shard2_replica1/ and leader is http://127.0.0.1:50535/_sje/h/awholynewcollection_0_shard2_replica1/
[junit4:junit4] 2> 650462 T2316 oasc.ZkController.register No LogReplay needed for core=awholynewcollection_0_shard2_replica1 baseURL=http://127.0.0.1:50535/_sje/h
[junit4:junit4] 2> 650462 T2256 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 650462 T2316 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 650463 T2316 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica1 state=active
[junit4:junit4] 2> 650464 T2256 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=3009
[junit4:junit4] 2> 650465 T2316 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 650466 T2300 oasc.ZkController.register We are http://127.0.0.1:53405/_sje/h/awholynewcollection_0_shard2_replica2/ and leader is http://127.0.0.1:50535/_sje/h/awholynewcollection_0_shard2_replica1/
[junit4:junit4] 2> 650467 T2300 oasc.ZkController.register No LogReplay needed for core=awholynewcollection_0_shard2_replica2 baseURL=http://127.0.0.1:53405/_sje/h
[junit4:junit4] 2> 650467 T2316 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=3012
[junit4:junit4] 2> 650467 T2300 oasc.ZkController.checkRecovery Core needs to recover:awholynewcollection_0_shard2_replica2
[junit4:junit4] 2> 650468 T2300 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 650469 T2344 C2143 P53405 oasc.RecoveryStrategy.run Starting recovery process. core=awholynewcollection_0_shard2_replica2 recoveringAfterStartup=true
[junit4:junit4] 2> 650469 T2344 C2143 P53405 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 650469 T2300 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 650487 T2285 oasc.ZkController.register We are http://127.0.0.1:55768/_sje/h/awholynewcollection_0_shard1_replica2/ and leader is http://127.0.0.1:40521/_sje/h/awholynewcollection_0_shard1_replica1/
[junit4:junit4] 2> ASYNC NEW_CORE C2144 name=awholynewcollection_0_shard2_replica2 org.apache.solr.core.SolrCore@6a344171 url=http://127.0.0.1:53405/_sje/h/awholynewcollection_0_shard2_replica2 node=127.0.0.1:53405__sje%2Fh C2144_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:53405__sje%2Fh, base_url=http://127.0.0.1:53405/_sje/h}
[junit4:junit4] 2> 650470 T2344 C2144 P53405 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica2 state=recovering
[junit4:junit4] 2> 650488 T2300 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=3032
[junit4:junit4] 2> 650487 T2285 oasc.ZkController.register No LogReplay needed for core=awholynewcollection_0_shard1_replica2 baseURL=http://127.0.0.1:55768/_sje/h
[junit4:junit4] 2> 650489 T2285 oasc.ZkController.checkRecovery Core needs to recover:awholynewcollection_0_shard1_replica2
[junit4:junit4] 2> 650489 T2285 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 650489 T2344 C2144 P53405 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C2145 name=awholynewcollection_0_shard1_replica2 org.apache.solr.core.SolrCore@63c9fa33 url=http://127.0.0.1:55768/_sje/h/awholynewcollection_0_shard1_replica2 node=127.0.0.1:55768__sje%2Fh C2145_STATE=coll:awholynewcollection_0 core:awholynewcollection_0_shard1_replica2 props:{shard=shard1, state=down, core=awholynewcollection_0_shard1_replica2, collection=awholynewcollection_0, node_name=127.0.0.1:55768__sje%2Fh, base_url=http://127.0.0.1:55768/_sje/h}
[junit4:junit4] 2> 650490 T2345 C2145 P55768 oasc.RecoveryStrategy.run Starting recovery process. core=awholynewcollection_0_shard1_replica2 recoveringAfterStartup=true
[junit4:junit4] 2> 650491 T2345 C2145 P55768 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 650491 T2285 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 650491 T2345 C2145 P55768 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica2 state=recovering
[junit4:junit4] 2> 650493 T2285 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=3038
[junit4:junit4] 2> 650493 T2345 C2145 P55768 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 650494 T2262 oasc.OverseerCollectionProcessor.createCollection Finished create command on all shards for collection: awholynewcollection_0
[junit4:junit4] 2> 650498 T2315 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:53405__sje%2Fh_awholynewcollection_0_shard2_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 650499 T2320 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work/qnr-0000000002 state: SyncConnected type NodeDataChanged
[junit4:junit4] 2> 650500 T2255 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:55768__sje%2Fh_awholynewcollection_0_shard1_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 650501 T2260 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 650501 T2262 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000002 complete, response:{success={null={responseHeader={status=0,QTime=3009},core=awholynewcollection_0_shard1_replica1},null={responseHeader={status=0,QTime=3012},core=awholynewcollection_0_shard2_replica1},null={responseHeader={status=0,QTime=3032},core=awholynewcollection_0_shard2_replica2},null={responseHeader={status=0,QTime=3038},core=awholynewcollection_0_shard1_replica2}}}
[junit4:junit4] 2> 650505 T2314 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/collections params={numShards=2&maxShardsPerNode=1&name=awholynewcollection_0&replicationFactor=2&action=CREATE&wt=javabin&version=2} status=0 QTime=3057
[junit4:junit4] 2> 650507 T2238 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 650510 T2238 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 650512 T2347 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c13dce6 name:ZooKeeperConnection Watcher:127.0.0.1:43772/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 650512 T2238 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 650514 T2238 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 650523 T2313 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=4&maxShardsPerNode=3&name=awholynewcollection_1&replicationFactor=3&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 650525 T2260 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 650527 T2262 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":"4",
[junit4:junit4] 2> "maxShardsPerNode":"3",
[junit4:junit4] 2> "createNodeSet":null,
[junit4:junit4] 2> "name":"awholynewcollection_1",
[junit4:junit4] 2> "replicationFactor":"3"}
[junit4:junit4] 2> 650527 T2262 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard1_replica1 as part of slice shard1 of collection awholynewcollection_1 on 127.0.0.1:50648__sje%2Fh
[junit4:junit4] 2> 650528 T2262 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard1_replica2 as part of slice shard1 of collection awholynewcollection_1 on 127.0.0.1:53405__sje%2Fh
[junit4:junit4] 2> 650528 T2262 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard1_replica3 as part of slice shard1 of collection awholynewcollection_1 on 127.0.0.1:55768__sje%2Fh
[junit4:junit4] 2> 650528 T2262 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard2_replica1 as part of slice shard2 of collection awholynewcollection_1 on 127.0.0.1:50535__sje%2Fh
[junit4:junit4] 2> 650529 T2262 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard2_replica2 as part of slice shard2 of collection awholynewcollection_1 on 127.0.0.1:40521__sje%2Fh
[junit4:junit4] 2> 650529 T2262 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard2_replica3 as part of slice shard2 of collection awholynewcollection_1 on 127.0.0.1:50648__sje%2Fh
[junit4:junit4] 2> 650530 T2273 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/awholynewcollection_1_shard1_replica1
[junit4:junit4] 2> 650531 T2273 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 2> 650530 T2299 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/awholynewcollection_1_shard1_replica2
[junit4:junit4] 2> 650532 T2273 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_1
[junit4:junit4] 2> 650532 T2273 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 650530 T2262 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard3_replica1 as part of slice shard3 of collection awholynewcollection_1 on 127.0.0.1:53405__sje%2Fh
[junit4:junit4] 2> 650532 T2272 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_1_shard2_replica3' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/awholynewcollection_1_shard2_replica3
[junit4:junit4] 2> 650534 T2272 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 2> 650532 T2299 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 2> 650535 T2272 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_1
[junit4:junit4] 2> 650532 T2254 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_1_shard2_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/awholynewcollection_1_shard2_replica2
[junit4:junit4] 2> 650531 T2287 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/awholynewcollection_1_shard1_replica3
[junit4:junit4] 2> 650537 T2287 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 2> 650531 T2314 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/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/awholynewcollection_1_shard2_replica1
[junit4:junit4] 2> 650536 T2254 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 2> 650536 T2272 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 650539 T2254 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_1
[junit4:junit4] 2> 650535 T2299 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_1
[junit4:junit4] 2> 650535 T2302 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_1_shard3_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/awholynewcollection_1_shard3_replica1
[junit4:junit4] 2> 650540 T2302 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 2> 650534 T2273 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 650542 T2302 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_1
[junit4:junit4] 2> 650542 T2302 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 650534 T2262 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard3_replica2 as part of slice shard3 of collection awholynewcollection_1 on 127.0.0.1:55768__sje%2Fh
[junit4:junit4] 2> 650542 T2273 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_1
[junit4:junit4] 2> 650540 T2299 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 650540 T2272 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 650545 T2272 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_1
[junit4:junit4] 2> 650539 T2254 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 650538 T2287 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_1
[junit4:junit4] 2> 650538 T2314 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 2> 650548 T2272 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 2> 650547 T2287 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 650547 T2254 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_1
[junit4:junit4] 2> 650547 T2273 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 2> 650550 T2287 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_1
[junit4:junit4] 2> 650546 T2299 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 650545 T2285 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_1_shard3_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/awholynewcollection_1_shard3_replica2
[junit4:junit4] 2> 650552 T2285 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 2> 650544 T2302 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 650543 T2262 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard3_replica3 as part of slice shard3 of collection awholynewcollection_1 on 127.0.0.1:50535__sje%2Fh
[junit4:junit4] 2> 650553 T2285 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 650553 T2287 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 2> 650553 T2302 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_1
[junit4:junit4] 2> 650552 T2254 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 2> 650552 T2273 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/awholynewcollection_1_shard1_replica1/'
[junit4:junit4] 2> 650551 T2299 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_1
[junit4:junit4] 2> 650550 T2272 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/awholynewcollection_1_shard2_replica3/'
[junit4:junit4] 2> 650549 T2314 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 650557 T2254 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/awholynewcollection_1_shard2_replica2/'
[junit4:junit4] 2> 650557 T2302 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 2> 650556 T2287 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/awholynewcollection_1_shard1_replica3/'
[junit4:junit4] 2> 650555 T2316 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_1_shard3_replica3' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/awholynewcollection_1_shard3_replica3
[junit4:junit4] 2> 650561 T2316 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 2> 650554 T2285 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 2> 650554 T2262 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard4_replica1 as part of slice shard4 of collection awholynewcollection_1 on 127.0.0.1:40521__sje%2Fh
[junit4:junit4] 2> 650562 T2316 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 650563 T2316 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 2> 650561 T2302 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/awholynewcollection_1_shard3_replica1/'
[junit4:junit4] 2> 650566 T2253 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_1_shard4_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/awholynewcollection_1_shard4_replica1
[junit4:junit4] 2> 650566 T2253 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 2> 650559 T2299 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 2> 650558 T2314 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 2> 650568 T2253 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 650568 T2316 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/awholynewcollection_1_shard3_replica3/'
[junit4:junit4] 2> 650564 T2262 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard4_replica2 as part of slice shard4 of collection awholynewcollection_1 on 127.0.0.1:50648__sje%2Fh
[junit4:junit4] 2> 650564 T2285 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1370431045943/awholynewcollection_1_shard3_replica2/'
[junit4:junit4] 2> 650571 T2262 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_1_shard4_replica3 as part of slice shard4 of collection awholynewcollection_1 on 127.0.0.1:53405__sje%2Fh
[junit4:junit4] 2> 650569 T2253 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 2> 650573 T2299 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/awholynewcollection_1_shard1_replica2/'
[junit4:junit4] 2> 650574 T2314 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1370431048302/awholynewcollection_1_shard2_replica1/'
[junit4:junit4] 2> 650576 T2301 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_1_shard4_replica3' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/awholynewcollection_1_shard4_replica3
[junit4:junit4] 2> 650576 T2301 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 2> 650577 T2253 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1370431044490/awholynewcollection_1_shard4_replica1/'
[junit4:junit4] 2> 650577 T2271 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_1_shard4_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/awholynewcollection_1_shard4_replica2
[junit4:junit4] 2> 650577 T2271 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 2> 650577 T2301 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 650578 T2301 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 2> 650578 T2271 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 650578 T2271 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 2> 650580 T2301 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1370431047106/awholynewcollection_1_shard4_replica3/'
[junit4:junit4] 2> 650581 T2271 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1370431044723/awholynewcollection_1_shard4_replica2/'
[junit4:junit4] 2> 650614 T2273 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 650626 T2272 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 650645 T2287 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 650651 T2302 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 650665 T2254 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 650668 T2316 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 650693 T2301 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 650697 T2271 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 650697 T2299 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 650720 T2314 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 650723 T2285 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 650746 T2253 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 650761 T2273 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 650763 T2273 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 650770 T2273 oass.IndexSchema.readSchema [awholynewcollection_1_shard1_replica1] Schema name=test
[junit4:junit4] 2> 650770 T2272 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 650781 T2272 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 650782 T2254 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 650784 T2254 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 650787 T2272 oass.IndexSchema.readSchema [awholynewcollection_1_shard2_replica3] Schema name=test
[junit4:junit4] 2> 650790 T2287 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 650791 T2254 oass.IndexSchema.readSchema [awholynewcollection_1_shard2_replica2] Schema name=test
[junit4:junit4] 2> 650793 T2287 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 650794 T2316 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 650805 T2316 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 650807 T2287 oass.IndexSchema.readSchema [awholynewcollection_1_shard1_replica3] Schema name=test
[junit4:junit4] 2> 650816 T2316 oass.IndexSchema.readSchema [awholynewcollection_1_shard3_replica3] Schema name=test
[junit4:junit4] 2> 650829 T2302 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 650832 T2302 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 650834 T2271 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 650836 T2314 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 650836 T2271 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 650840 T2302 oass.IndexSchema.readSchema [awholynewcollection_1_shard3_replica1] Schema name=test
[junit4:junit4] 2> 650841 T2314 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 650860 T2299 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 650860 T2271 oass.IndexSchema.readSchema [awholynewcollection_1_shard4_replica2] Schema name=test
[junit4:junit4] 2> 650862 T2299 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 650862 T2301 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 650862 T2314 oass.IndexSchema.readSchema [awholynewcollection_1_shard2_replica1] Schema name=test
[junit4:junit4] 2> 650865 T2301 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 650868 T2299 oass.IndexSchema.readSchema [awholynewcollection_1_shard1_replica2] Schema name=test
[junit4:junit4] 2> 650873 T2301 oass.IndexSchema.readSchema [awholynewcollection_1_shard4_replica3] Schema name=test
[junit4:junit4] 2> 650887 T2285 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 650887 T2253 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 650891 T2285 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 650891 T2253 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 650899 T2285 oass.IndexSchema.readSchema [awholynewcollection_1_shard3_replica2] Schema name=test
[junit4:junit4] 2> 650903 T2253 oass.IndexSchema.readSchema [awholynewcollection_1_shard4_replica1] Schema name=test
[junit4:junit4] 2> ASYNC NEW_CORE C2146 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@64c01405 url=http://127.0.0.1:53405/_sje/h/nodes_used_collection_shard2_replica1 node=127.0.0.1:53405__sje%2Fh C2146_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=recovering, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:53405__sje%2Fh, base_url=http://127.0.0.1:53405/_sje/h}
[junit4:junit4] 2> 651398 T2332 C2146 P53405 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:50535/_sje/h/nodes_used_collection_shard2_replica2/ core=nodes_used_collection_shard2_replica1 - recoveringAfterStartup=true
[junit4:junit4] 2> ASYNC NEW_CORE C2147 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@7e6287ef url=http://127.0.0.1:50648/_sje/h/nodes_used_collection_shard1_replica1 node=127.0.0.1:50648__sje%2Fh C2147_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica1 props:{shard=shard1, state=recovering, core=nodes_used_collection_shard1_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50648__sje%2Fh, base_url=http://127.0.0.1:50648/_sje/h}
[junit4:junit4] 2> 651399 T2333 C2147 P50648 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:40521/_sje/h/nodes_used_collection_shard1_replica2/ core=nodes_used_collection_shard1_replica1 - recoveringAfterStartup=true
[junit4:junit4] 2> 651399 T2332 C2146 P53405 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:53405/_sje/h START replicas=[http://127.0.0.1:50535/_sje/h/nodes_used_collection_shard2_replica2/] nUpdates=100
[junit4:junit4] 2> 651399 T2333 C2147 P50648 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:50648/_sje/h START replicas=[http://127.0.0.1:40521/_sje/h/nodes_used_collection_shard1_replica2/] nUpdates=100
[junit4:junit4] 2> ASYNC NEW_CORE C2148 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@64c01405 url=http://127.0.0.1:53405/_sje/h/nodes_used_collection_shard2_replica1 node=127.0.0.1:53405__sje%2Fh C2148_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=recovering, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:53405__sje%2Fh, base_url=http://127.0.0.1:53405/_sje/h}
[junit4:junit4] 2> 651407 T2332 C2148 P53405 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 651407 T2332 C2148 P53405 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 651408 T2332 C2148 P53405 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 651408 T2332 C2148 P53405 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 651408 T2332 C2148 P53405 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 651408 T2332 C2148 P53405 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:50535/_sje/h/nodes_used_collection_shard2_replica2/. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 651409 T2332 C2148 P53405 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C2149 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@7e6287ef url=http://127.0.0.1:50648/_sje/h/nodes_used_collection_shard1_replica1 node=127.0.0.1:50648__sje%2Fh C2149_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica1 props:{shard=shard1, state=recovering, core=nodes_used_collection_shard1_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50648__sje%2Fh, base_url=http://127.0.0.1:50648/_sje/h}
[junit4:junit4] 2> 651414 T2333 C2149 P50648 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 651414 T2333 C2149 P50648 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 651415 T2333 C2149 P50648 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 651415 T2333 C2149 P50648 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 651415 T2333 C2149 P50648 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 651415 T2333 C2149 P50648 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:40521/_sje/h/nodes_used_collection_shard1_replica2/. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 651416 T2333 C2149 P50648 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C2150 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@7bcadd5e url=http://127.0.0.1:50535/_sje/h/nodes_used_collection_shard2_replica2 node=127.0.0.1:50535__sje%2Fh C2150_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica2 props:{shard=shard2, state=active, core=nodes_used_collection_shard2_replica2, collection=nodes_used_collection, node_name=127.0.0.1:50535__sje%2Fh, base_url=http://127.0.0.1:50535/_sje/h, leader=true}
[junit4:junit4] 2> 651420 T2357 C2150 P50535 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> ASYNC NEW
[...truncated too long message...]
ions/awholynewcollection_1/leaders/shard3 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "core":"awholynewcollection_1_shard3_replica3",
[junit4:junit4] 1> "node_name":"127.0.0.1:50535__sje%2Fh",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:50535/_sje/h"}
[junit4:junit4] 1> /solr/overseer_elect (2)
[junit4:junit4] 1> /solr/overseer_elect/election (5)
[junit4:junit4] 1> /solr/overseer_elect/election/89812568920489987-127.0.0.1:40521__sje%2Fh-n_0000000000 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89812568920489994-127.0.0.1:53405__sje%2Fh-n_0000000003 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89812568920489990-127.0.0.1:50648__sje%2Fh-n_0000000001 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89812568920489996-127.0.0.1:50535__sje%2Fh-n_0000000004 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89812568920489992-127.0.0.1:55768__sje%2Fh-n_0000000002 (0)
[junit4:junit4] 1> /solr/overseer_elect/leader (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"id":"89812568920489987-127.0.0.1:40521__sje%2Fh-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=D0C55A4E175D25A9 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=sr_BA_#Latn -Dtests.timezone=America/Cambridge_Bay -Dtests.file.encoding=UTF-8
[junit4:junit4] FAILURE 269s J1 | CollectionsAPIDistributedZkTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: java.lang.AssertionError: There are still nodes recoverying - waited for 230 seconds
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([D0C55A4E175D25A9:5123D45660024595]: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:722)
[junit4:junit4] 2> 908496 T2238 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 269122 T2237 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4] 2> 909667 T2320 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 909667 T2320 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> 909667 T2320 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 909668 T2320 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/awholynewcollection_1/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> 909669 T2320 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/awholynewcollection_1/leader_elect/shard3/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> NOTE: test params are: codec=DummyCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=DUMMY, chunkSize=412), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=DUMMY, chunkSize=412)), sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=sr_BA_#Latn, timezone=America/Cambridge_Bay
[junit4:junit4] 2> NOTE: Linux 3.2.0-45-generic amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=8,threads=1,free=38676888,total=214802432
[junit4:junit4] 2> NOTE: All tests run in this JVM: [MultiTermTest, HighlighterTest, TestShardHandlerFactory, TestFieldResource, SpellPossibilityIteratorTest, SolrRequestParserTest, TestElisionMultitermQuery, TestSchemaVersionResource, TestQueryTypes, BadIndexSchemaTest, TestWordDelimiterFilterFactory, LeaderElectionIntegrationTest, TestNumberUtils, SolrCoreCheckLockOnStartupTest, HighlighterConfigTest, TestAddFieldRealTimeGet, DisMaxRequestHandlerTest, TestAnalyzedSuggestions, ZkSolrClientTest, TestSerializedLuceneMatchVersion, DistanceFunctionTest, TestRecovery, UpdateParamsTest, TestRangeQuery, RequiredFieldsTest, TestRandomFaceting, TestHashPartitioner, TestIndexSearcher, TestManagedSchemaFieldResource, HardAutoCommitTest, TestBinaryResponseWriter, TestFieldTypeCollectionResource, TestClassNameShortening, TestLMJelinekMercerSimilarityFactory, CurrencyFieldXmlFileTest, TestPropInject, TestPostingsSolrHighlighter, TestLuceneMatchVersion, TestSolrJ, SpellCheckCollatorTest, TestBM25SimilarityFactory, NotRequiredUniqueKeyTest, TestIndexingPerformance, StandardRequestHandlerTest, TestStressReorder, TestFastOutputStream, TestDynamicFieldResource, TermVectorComponentDistributedTest, CurrencyFieldOpenExchangeTest, TestSolrQueryParserDefaultOperatorResource, TestSchemaNameResource, TestAtomicUpdateErrorCases, XmlUpdateRequestHandlerTest, DirectUpdateHandlerTest, TestOmitPositions, TestZkChroot, OutputWriterTest, XsltUpdateRequestHandlerTest, URLClassifyProcessorTest, TestDFRSimilarityFactory, ZkNodePropsTest, TestCopyFieldCollectionResource, TestCSVLoader, TestDistributedGrouping, IndexBasedSpellCheckerTest, SuggesterWFSTTest, FullSolrCloudDistribCmdsTest, NoCacheHeaderTest, OpenExchangeRatesOrgProviderTest, PathHierarchyTokenizerFactoryTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest]
[junit4:junit4] Completed on J1 in 270.41s, 1 test, 1 failure <<< FAILURES!
[...truncated 446 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: 297 suites, 1244 tests, 1 failure, 13 ignored (7 assumptions)
Total time: 40 minutes 5 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_21 -XX:-UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure