You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/05/16 06:01:27 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/ibm-j9-jdk7) - Build #
5676 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/5676/
Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
1 tests failed.
REGRESSION: org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch
Error Message:
Server at http://127.0.0.1:44823/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:44823/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
at __randomizedtesting.SeedInfo.seed([F21F84F2B0C5589B:73F90AEAC79A38A7]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:198)
at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:90)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
at java.lang.reflect.Method.invoke(Method.java:613)
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:780)
Build Log:
[...truncated 9555 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4] 2> 470946 T1593 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 470950 T1593 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1368676135696
[junit4:junit4] 2> 470951 T1593 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 470951 T1594 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 471051 T1593 oasc.ZkTestServer.run start zk server on port:41830
[junit4:junit4] 2> 471053 T1593 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 471120 T1600 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1569a3b2 name:ZooKeeperConnection Watcher:127.0.0.1:41830 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 471120 T1593 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 471121 T1593 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 471125 T1593 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 471126 T1602 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b4e6ca5 name:ZooKeeperConnection Watcher:127.0.0.1:41830/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 471126 T1593 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 471127 T1593 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 471130 T1593 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 471134 T1593 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 471136 T1593 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 471138 T1593 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 471138 T1593 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 471141 T1593 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 471142 T1593 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 471145 T1593 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 471145 T1593 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 471147 T1593 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 471148 T1593 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 471150 T1593 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 471151 T1593 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 471153 T1593 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 471154 T1593 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 471156 T1593 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 471156 T1593 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 471159 T1593 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 471159 T1593 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 471161 T1593 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 471162 T1593 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 471231 T1593 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 471246 T1593 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:60339
[junit4:junit4] 2> 471247 T1593 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 471247 T1593 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 471248 T1593 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1368676135910
[junit4:junit4] 2> 471249 T1593 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1368676135910/solr.xml
[junit4:junit4] 2> 471249 T1593 oasc.CoreContainer.<init> New CoreContainer 406827390
[junit4:junit4] 2> 471250 T1593 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1368676135910/'
[junit4:junit4] 2> 471250 T1593 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1368676135910/'
[junit4:junit4] 2> 471291 T1593 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 471291 T1593 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 471292 T1593 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 471293 T1593 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 471293 T1593 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 471294 T1593 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 471294 T1593 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 471295 T1593 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 471296 T1593 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 471296 T1593 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 471301 T1593 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 471302 T1593 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:41830/solr
[junit4:junit4] 2> 471302 T1593 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 471303 T1593 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 471305 T1613 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@40794c18 name:ZooKeeperConnection Watcher:127.0.0.1:41830 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 471305 T1593 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 471307 T1593 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 471312 T1593 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 471313 T1615 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9f47bcb5 name:ZooKeeperConnection Watcher:127.0.0.1:41830/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 471313 T1593 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 471315 T1593 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 471318 T1593 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 471322 T1593 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 471324 T1593 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60339_
[junit4:junit4] 2> 471326 T1593 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60339_
[junit4:junit4] 2> 471329 T1593 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 471334 T1593 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 471337 T1593 oasc.Overseer.start Overseer (id=89697559229169667-127.0.0.1:60339_-n_0000000000) starting
[junit4:junit4] 2> 471340 T1593 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 471344 T1617 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 471344 T1593 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 471348 T1593 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 471350 T1593 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 471353 T1616 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 471357 T1618 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1368676135910/collection1
[junit4:junit4] 2> 471357 T1618 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 471358 T1618 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 471358 T1618 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 471359 T1618 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1368676135910/collection1/'
[junit4:junit4] 2> 471360 T1618 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1368676135910/collection1/lib/README' to classloader
[junit4:junit4] 2> 471360 T1618 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1368676135910/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 471396 T1618 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 471436 T1618 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 471437 T1618 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 471442 T1618 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 471776 T1618 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 471781 T1618 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 471784 T1618 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 471792 T1618 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 471796 T1618 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 471800 T1618 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 471801 T1618 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 471802 T1618 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 471802 T1618 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 471804 T1618 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 471804 T1618 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 471804 T1618 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 471805 T1618 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1368676135910/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/control/data/
[junit4:junit4] 2> 471805 T1618 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@f45fa2e
[junit4:junit4] 2> 471806 T1618 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 471807 T1618 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/control/data
[junit4:junit4] 2> 471807 T1618 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/control/data/index/
[junit4:junit4] 2> 471807 T1618 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 471808 T1618 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/control/data/index
[junit4:junit4] 2> 471810 T1618 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b4df5da lockFactory=org.apache.lucene.store.NativeFSLockFactory@a7e0644f),segFN=segments_1,generation=1}
[junit4:junit4] 2> 471810 T1618 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 471813 T1618 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 471813 T1618 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 471814 T1618 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 471815 T1618 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 471816 T1618 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 471816 T1618 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 471817 T1618 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 471818 T1618 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 471818 T1618 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 471820 T1618 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 471822 T1618 oass.SolrIndexSearcher.<init> Opening Searcher@9ce787f2 main
[junit4:junit4] 2> 471823 T1618 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/control/data/tlog
[junit4:junit4] 2> 471824 T1618 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 471824 T1618 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 471827 T1619 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9ce787f2 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 471827 T1618 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 471827 T1618 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 472856 T1616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 472856 T1616 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:60339",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:60339_",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 472857 T1616 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 472857 T1616 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 472860 T1615 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 473829 T1618 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 473829 T1618 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:60339 collection:control_collection shard:shard1
[junit4:junit4] 2> 473830 T1618 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 473835 T1618 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 473837 T1618 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 473837 T1618 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 473837 T1618 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:60339/collection1/
[junit4:junit4] 2> 473838 T1618 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 473838 T1618 oasc.SyncStrategy.syncToMe http://127.0.0.1:60339/collection1/ has no replicas
[junit4:junit4] 2> 473839 T1618 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:60339/collection1/
[junit4:junit4] 2> 473839 T1618 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 474363 T1616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 474371 T1615 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 474394 T1618 oasc.ZkController.register We are http://127.0.0.1:60339/collection1/ and leader is http://127.0.0.1:60339/collection1/
[junit4:junit4] 2> 474395 T1618 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60339
[junit4:junit4] 2> 474395 T1618 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 474396 T1618 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 474396 T1618 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 474398 T1618 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 474399 T1593 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 474400 T1593 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 474401 T1593 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 474407 T1593 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 474409 T1593 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 474411 T1622 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e576c5a9 name:ZooKeeperConnection Watcher:127.0.0.1:41830/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 474412 T1593 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 474413 T1593 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 474415 T1593 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 474481 T1593 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 474484 T1593 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52325
[junit4:junit4] 2> 474485 T1593 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 474486 T1593 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 474487 T1593 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1368676139162
[junit4:junit4] 2> 474488 T1593 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1368676139162/solr.xml
[junit4:junit4] 2> 474488 T1593 oasc.CoreContainer.<init> New CoreContainer 258034597
[junit4:junit4] 2> 474489 T1593 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1368676139162/'
[junit4:junit4] 2> 474490 T1593 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1368676139162/'
[junit4:junit4] 2> 474537 T1593 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 474537 T1593 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 474538 T1593 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 474539 T1593 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 474539 T1593 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 474540 T1593 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 474540 T1593 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 474541 T1593 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 474541 T1593 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 474542 T1593 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 474546 T1593 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 474547 T1593 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:41830/solr
[junit4:junit4] 2> 474547 T1593 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 474548 T1593 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 474550 T1633 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51b8c0f4 name:ZooKeeperConnection Watcher:127.0.0.1:41830 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 474550 T1593 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 474552 T1593 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 474556 T1593 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 474558 T1635 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b10a233b name:ZooKeeperConnection Watcher:127.0.0.1:41830/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 474558 T1593 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 474561 T1593 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 475564 T1593 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52325_
[junit4:junit4] 2> 475566 T1593 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52325_
[junit4:junit4] 2> 475568 T1622 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 475568 T1615 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 475568 T1635 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 475569 T1615 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 475572 T1636 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1368676139162/collection1
[junit4:junit4] 2> 475573 T1636 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 475574 T1636 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 475574 T1636 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 475575 T1636 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1368676139162/collection1/'
[junit4:junit4] 2> 475576 T1636 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1368676139162/collection1/lib/README' to classloader
[junit4:junit4] 2> 475576 T1636 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1368676139162/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 475599 T1636 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 475635 T1636 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 475636 T1636 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 475641 T1636 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 475875 T1616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 475876 T1616 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:60339",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:60339__collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:60339_",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 475879 T1635 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 475879 T1615 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 475880 T1622 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 475956 T1636 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 475960 T1636 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 475963 T1636 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 475972 T1636 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 475975 T1636 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 475979 T1636 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 475980 T1636 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 475980 T1636 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 475981 T1636 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 475982 T1636 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 475982 T1636 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 475982 T1636 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 475983 T1636 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1368676139162/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty1/
[junit4:junit4] 2> 475983 T1636 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@f45fa2e
[junit4:junit4] 2> 475984 T1636 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 475984 T1636 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty1
[junit4:junit4] 2> 475985 T1636 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty1/index/
[junit4:junit4] 2> 475985 T1636 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 475986 T1636 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty1/index
[junit4:junit4] 2> 475987 T1636 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6af7a869 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9d131394),segFN=segments_1,generation=1}
[junit4:junit4] 2> 475987 T1636 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 475989 T1636 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 475989 T1636 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 475990 T1636 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 475991 T1636 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 475991 T1636 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 475991 T1636 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 475992 T1636 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 475992 T1636 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 475993 T1636 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 475994 T1636 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 475996 T1636 oass.SolrIndexSearcher.<init> Opening Searcher@d27cba6 main
[junit4:junit4] 2> 475996 T1636 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty1/tlog
[junit4:junit4] 2> 475997 T1636 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 475997 T1636 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 476002 T1637 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@d27cba6 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 476004 T1636 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 476004 T1636 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 477383 T1616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 477384 T1616 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52325",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:52325_",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 477384 T1616 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 477384 T1616 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 477388 T1615 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 477388 T1635 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 477388 T1622 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 478006 T1636 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 478006 T1636 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52325 collection:collection1 shard:shard1
[junit4:junit4] 2> 478007 T1636 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 478012 T1636 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 478014 T1636 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 478014 T1636 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 478014 T1636 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52325/collection1/
[junit4:junit4] 2> 478015 T1636 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 478015 T1636 oasc.SyncStrategy.syncToMe http://127.0.0.1:52325/collection1/ has no replicas
[junit4:junit4] 2> 478015 T1636 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52325/collection1/
[junit4:junit4] 2> 478016 T1636 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 478891 T1616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 478898 T1615 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 478898 T1635 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 478898 T1622 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 478921 T1636 oasc.ZkController.register We are http://127.0.0.1:52325/collection1/ and leader is http://127.0.0.1:52325/collection1/
[junit4:junit4] 2> 478922 T1636 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52325
[junit4:junit4] 2> 478922 T1636 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 478922 T1636 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 478923 T1636 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 478924 T1636 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 478925 T1593 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 478926 T1593 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 478927 T1593 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 479010 T1593 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 479012 T1593 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44823
[junit4:junit4] 2> 479013 T1593 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 479013 T1593 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 479014 T1593 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1368676143679
[junit4:junit4] 2> 479014 T1593 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1368676143679/solr.xml
[junit4:junit4] 2> 479015 T1593 oasc.CoreContainer.<init> New CoreContainer 1516863868
[junit4:junit4] 2> 479016 T1593 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1368676143679/'
[junit4:junit4] 2> 479016 T1593 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1368676143679/'
[junit4:junit4] 2> 479057 T1593 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 479058 T1593 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 479058 T1593 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 479059 T1593 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 479060 T1593 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 479060 T1593 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 479061 T1593 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 479061 T1593 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 479062 T1593 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 479063 T1593 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 479067 T1593 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 479068 T1593 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:41830/solr
[junit4:junit4] 2> 479069 T1593 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 479070 T1593 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 479071 T1649 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2d575e79 name:ZooKeeperConnection Watcher:127.0.0.1:41830 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 479072 T1593 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 479074 T1593 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 479079 T1593 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 479080 T1651 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b9578526 name:ZooKeeperConnection Watcher:127.0.0.1:41830/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 479080 T1593 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 479083 T1593 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 480086 T1593 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44823_
[junit4:junit4] 2> 480089 T1593 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44823_
[junit4:junit4] 2> 480092 T1615 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 480092 T1622 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 480092 T1615 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 480092 T1635 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 480092 T1651 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 480092 T1622 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 480093 T1635 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 480096 T1652 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1368676143679/collection1
[junit4:junit4] 2> 480097 T1652 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 480097 T1652 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 480097 T1652 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 480099 T1652 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1368676143679/collection1/'
[junit4:junit4] 2> 480099 T1652 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1368676143679/collection1/lib/README' to classloader
[junit4:junit4] 2> 480100 T1652 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1368676143679/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 480123 T1652 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 480153 T1652 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 480154 T1652 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 480159 T1652 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 480402 T1616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 480402 T1616 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52325",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:52325__collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:52325_",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 480405 T1615 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 480405 T1622 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 480405 T1651 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 480405 T1635 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 480476 T1652 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 480481 T1652 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 480483 T1652 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 480493 T1652 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 480497 T1652 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 480500 T1652 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 480501 T1652 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 480502 T1652 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 480502 T1652 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 480503 T1652 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 480504 T1652 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 480504 T1652 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 480504 T1652 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1368676143679/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty2/
[junit4:junit4] 2> 480505 T1652 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@f45fa2e
[junit4:junit4] 2> 480505 T1652 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 480506 T1652 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty2
[junit4:junit4] 2> 480506 T1652 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty2/index/
[junit4:junit4] 2> 480507 T1652 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 480507 T1652 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty2/index
[junit4:junit4] 2> 480509 T1652 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@d5ad2ac6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@487cc5c9),segFN=segments_1,generation=1}
[junit4:junit4] 2> 480509 T1652 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 480510 T1652 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 480511 T1652 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 480511 T1652 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 480512 T1652 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 480513 T1652 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 480513 T1652 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 480513 T1652 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 480514 T1652 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 480514 T1652 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 480515 T1652 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 480517 T1652 oass.SolrIndexSearcher.<init> Opening Searcher@692dffbf main
[junit4:junit4] 2> 480518 T1652 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty2/tlog
[junit4:junit4] 2> 480518 T1652 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 480519 T1652 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 480522 T1653 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@692dffbf main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 480524 T1652 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 480524 T1652 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 481909 T1616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 481909 T1616 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44823",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:44823_",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 481910 T1616 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 481910 T1616 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 481914 T1615 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 481915 T1635 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 481914 T1622 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 481914 T1651 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 482525 T1652 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 482526 T1652 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:44823 collection:collection1 shard:shard2
[junit4:junit4] 2> 482527 T1652 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 482534 T1652 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 482536 T1652 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 482536 T1652 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 482537 T1652 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:44823/collection1/
[junit4:junit4] 2> 482537 T1652 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 482537 T1652 oasc.SyncStrategy.syncToMe http://127.0.0.1:44823/collection1/ has no replicas
[junit4:junit4] 2> 482538 T1652 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:44823/collection1/
[junit4:junit4] 2> 482538 T1652 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 483418 T1616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 483439 T1615 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 483439 T1651 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 483439 T1635 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 483439 T1622 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 483443 T1652 oasc.ZkController.register We are http://127.0.0.1:44823/collection1/ and leader is http://127.0.0.1:44823/collection1/
[junit4:junit4] 2> 483444 T1652 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44823
[junit4:junit4] 2> 483444 T1652 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 483444 T1652 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 483444 T1652 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 483446 T1652 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 483447 T1593 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 483447 T1593 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 483448 T1593 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 483518 T1593 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 483520 T1593 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:33247
[junit4:junit4] 2> 483521 T1593 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 483522 T1593 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 483522 T1593 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1368676148199
[junit4:junit4] 2> 483523 T1593 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1368676148199/solr.xml
[junit4:junit4] 2> 483523 T1593 oasc.CoreContainer.<init> New CoreContainer 2081907553
[junit4:junit4] 2> 483524 T1593 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1368676148199/'
[junit4:junit4] 2> 483525 T1593 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1368676148199/'
[junit4:junit4] 2> 483564 T1593 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 483564 T1593 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 483565 T1593 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 483565 T1593 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 483566 T1593 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 483567 T1593 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 483568 T1593 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 483569 T1593 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 483570 T1593 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 483570 T1593 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 483574 T1593 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 483575 T1593 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:41830/solr
[junit4:junit4] 2> 483576 T1593 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 483577 T1593 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 483578 T1665 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@45cfdec8 name:ZooKeeperConnection Watcher:127.0.0.1:41830 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 483578 T1593 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 483580 T1593 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 483584 T1593 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 483586 T1667 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e34d0f4c name:ZooKeeperConnection Watcher:127.0.0.1:41830/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 483586 T1593 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 483589 T1593 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 484592 T1593 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33247_
[junit4:junit4] 2> 484593 T1593 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:33247_
[junit4:junit4] 2> 484595 T1651 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 484596 T1635 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 484596 T1622 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 484596 T1615 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 484596 T1635 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 484596 T1667 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 484597 T1615 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 484598 T1651 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 484596 T1622 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 484601 T1668 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1368676148199/collection1
[junit4:junit4] 2> 484602 T1668 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 484602 T1668 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 484603 T1668 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 484603 T1668 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1368676148199/collection1/'
[junit4:junit4] 2> 484604 T1668 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1368676148199/collection1/lib/README' to classloader
[junit4:junit4] 2> 484604 T1668 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1368676148199/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 484631 T1668 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 484671 T1668 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 484673 T1668 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 484679 T1668 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 484944 T1616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 484945 T1616 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44823",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:44823__collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:44823_",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 484948 T1667 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 484948 T1651 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 484948 T1615 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 484948 T1635 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 484948 T1622 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 485056 T1668 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 485061 T1668 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 485063 T1668 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 485073 T1668 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 485077 T1668 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 485080 T1668 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 485081 T1668 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 485082 T1668 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 485082 T1668 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 485083 T1668 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 485083 T1668 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 485084 T1668 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 485084 T1668 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1368676148199/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty3/
[junit4:junit4] 2> 485084 T1668 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@f45fa2e
[junit4:junit4] 2> 485085 T1668 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 485086 T1668 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty3
[junit4:junit4] 2> 485086 T1668 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty3/index/
[junit4:junit4] 2> 485086 T1668 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 485087 T1668 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty3/index
[junit4:junit4] 2> 485088 T1668 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2e9249c8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@ca973eb9),segFN=segments_1,generation=1}
[junit4:junit4] 2> 485088 T1668 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 485090 T1668 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 485090 T1668 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 485091 T1668 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 485092 T1668 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 485092 T1668 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 485092 T1668 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 485093 T1668 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 485093 T1668 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 485094 T1668 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 485095 T1668 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 485097 T1668 oass.SolrIndexSearcher.<init> Opening Searcher@a1bef745 main
[junit4:junit4] 2> 485097 T1668 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty3/tlog
[junit4:junit4] 2> 485098 T1668 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 485098 T1668 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 485103 T1669 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@a1bef745 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 485104 T1668 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 485105 T1668 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 486472 T1616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 486472 T1616 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:33247",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:33247_",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 486472 T1616 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 486473 T1616 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 486476 T1651 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 486476 T1635 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 486476 T1667 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 486476 T1622 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 486476 T1615 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 487107 T1668 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 487107 T1668 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:33247 collection:collection1 shard:shard1
[junit4:junit4] 2> 487111 T1668 oasc.ZkController.register We are http://127.0.0.1:33247/collection1/ and leader is http://127.0.0.1:52325/collection1/
[junit4:junit4] 2> 487111 T1668 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:33247
[junit4:junit4] 2> 487112 T1668 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 487112 T1668 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C112 name=collection1 org.apache.solr.core.SolrCore@c9100bb6 url=http://127.0.0.1:33247/collection1 node=127.0.0.1:33247_ C112_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:33247, state=down, node_name=127.0.0.1:33247_, collection=collection1, core=collection1}
[junit4:junit4] 2> 487113 T1670 C112 P33247 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 487114 T1670 C112 P33247 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 487114 T1668 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 487114 T1670 C112 P33247 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 487115 T1670 C112 P33247 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 487115 T1593 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 487116 T1593 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 487115 T1670 C112 P33247 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 487117 T1593 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 487122 T1630 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:33247__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 487201 T1593 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 487203 T1593 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36186
[junit4:junit4] 2> 487204 T1593 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 487205 T1593 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 487206 T1593 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1368676151868
[junit4:junit4] 2> 487207 T1593 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1368676151868/solr.xml
[junit4:junit4] 2> 487208 T1593 oasc.CoreContainer.<init> New CoreContainer 1942710571
[junit4:junit4] 2> 487209 T1593 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1368676151868/'
[junit4:junit4] 2> 487210 T1593 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1368676151868/'
[junit4:junit4] 2> 487261 T1593 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 487262 T1593 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 487262 T1593 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 487263 T1593 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 487263 T1593 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 487264 T1593 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 487265 T1593 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 487265 T1593 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 487266 T1593 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 487267 T1593 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 487271 T1593 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 487271 T1593 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:41830/solr
[junit4:junit4] 2> 487272 T1593 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 487273 T1593 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 487275 T1682 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fc51c83d name:ZooKeeperConnection Watcher:127.0.0.1:41830 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 487275 T1593 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 487277 T1593 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 487284 T1593 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 487285 T1684 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a8450ab7 name:ZooKeeperConnection Watcher:127.0.0.1:41830/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 487285 T1593 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 487288 T1593 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 487979 T1616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 487980 T1616 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:33247",
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:33247__collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:33247_",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 487984 T1651 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 487984 T1615 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 487984 T1635 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 487984 T1622 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 487984 T1667 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 487984 T1684 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 488123 T1630 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:33247__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 488124 T1630 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={state=recovering&onlyIfLeader=true&checkLive=true&action=PREPRECOVERY&version=2&coreNodeName=127.0.0.1:33247__collection1&wt=javabin&nodeName=127.0.0.1:33247_&core=collection1} status=0 QTime=1002
[junit4:junit4] 2> 488292 T1593 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36186_
[junit4:junit4] 2> 488294 T1593 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36186_
[junit4:junit4] 2> 488297 T1651 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 488297 T1667 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 488297 T1622 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 488297 T1615 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 488297 T1635 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 488298 T1651 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 488298 T1635 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 488298 T1622 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 488298 T1615 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 488299 T1667 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 488298 T1684 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 488301 T1684 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 488304 T1685 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1368676151868/collection1
[junit4:junit4] 2> 488304 T1685 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 488304 T1685 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 488305 T1685 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 488306 T1685 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1368676151868/collection1/'
[junit4:junit4] 2> 488307 T1685 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1368676151868/collection1/lib/README' to classloader
[junit4:junit4] 2> 488308 T1685 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1368676151868/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 488332 T1685 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 488362 T1685 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 488363 T1685 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 488369 T1685 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 488708 T1685 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 488713 T1685 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 488716 T1685 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 488724 T1685 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 488728 T1685 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 488731 T1685 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 488732 T1685 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 488733 T1685 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 488733 T1685 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 488734 T1685 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 488735 T1685 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 488735 T1685 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 488735 T1685 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1368676151868/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty4/
[junit4:junit4] 2> 488736 T1685 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@f45fa2e
[junit4:junit4] 2> 488737 T1685 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 488737 T1685 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty4
[junit4:junit4] 2> 488738 T1685 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty4/index/
[junit4:junit4] 2> 488738 T1685 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 488739 T1685 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty4/index
[junit4:junit4] 2> 488740 T1685 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@60e970e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@eafd0694),segFN=segments_1,generation=1}
[junit4:junit4] 2> 488741 T1685 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 488742 T1685 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 488743 T1685 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 488744 T1685 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 488744 T1685 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 488745 T1685 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 488745 T1685 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 488746 T1685 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 488746 T1685 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 488747 T1685 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 488748 T1685 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 488750 T1685 oass.SolrIndexSearcher.<init> Opening Searcher@2b946164 main
[junit4:junit4] 2> 488751 T1685 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty4/tlog
[junit4:junit4] 2> 488752 T1685 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 488752 T1685 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 488757 T1686 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2b946164 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 488758 T1685 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 488759 T1685 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 489491 T1616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 489492 T1616 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36186",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:36186_",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 489493 T1616 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 489493 T1616 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 489497 T1667 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> 489497 T1622 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> 489497 T1651 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> 489497 T1635 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> 489497 T1615 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> 489497 T1684 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> 489760 T1685 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 489761 T1685 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36186 collection:collection1 shard:shard2
[junit4:junit4] 2> 489764 T1685 oasc.ZkController.register We are http://127.0.0.1:36186/collection1/ and leader is http://127.0.0.1:44823/collection1/
[junit4:junit4] 2> 489764 T1685 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36186
[junit4:junit4] 2> 489764 T1685 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 489764 T1685 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C113 name=collection1 org.apache.solr.core.SolrCore@e0298c43 url=http://127.0.0.1:36186/collection1 node=127.0.0.1:36186_ C113_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:36186, state=down, node_name=127.0.0.1:36186_, collection=collection1, core=collection1}
[junit4:junit4] 2> 489765 T1687 C113 P36186 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 489765 T1687 C113 P36186 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 489766 T1687 C113 P36186 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 489766 T1685 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 489766 T1687 C113 P36186 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 489767 T1593 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 489768 T1593 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 489767 T1687 C113 P36186 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 489768 T1593 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 489775 T1646 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:36186__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 489776 T1593 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 489778 T1593 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 489783 T1628 oasc.CoreContainer.create Creating SolrCore 'onenodecollectioncore' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1368676139162/onenodecollectioncore
[junit4:junit4] 2> 489783 T1628 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4] 2> 489784 T1628 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4] 2> 489785 T1628 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 489786 T1628 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 489787 T1628 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4] 2> 489789 T1628 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4] 2> 489790 T1628 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1368676139162/onenodecollectioncore/'
[junit4:junit4] 2> 489819 T1628 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 489856 T1628 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 489857 T1628 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 489862 T1628 oass.IndexSchema.readSchema [onenodecollectioncore] Schema name=test
[junit4:junit4] 2> C112_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:33247, state=recovering, node_name=127.0.0.1:33247_, collection=collection1, shard=shard1, core=collection1}
[junit4:junit4] 2> 490125 T1670 C112 P33247 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:52325/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 490126 T1670 C112 P33247 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:33247 START replicas=[http://127.0.0.1:52325/collection1/] nUpdates=100
[junit4:junit4] 2> 490126 T1670 C112 P33247 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 490126 T1670 C112 P33247 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 490126 T1670 C112 P33247 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 490127 T1670 C112 P33247 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 490127 T1670 C112 P33247 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 490127 T1670 C112 P33247 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:52325/collection1/. core=collection1
[junit4:junit4] 2> 490127 T1670 C112 P33247 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 490193 T1628 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 490198 T1628 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 490201 T1628 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 490211 T1628 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 490215 T1628 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 490219 T1628 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 490220 T1628 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 490221 T1628 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 490221 T1628 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 490223 T1628 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 490223 T1628 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 490224 T1628 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 490224 T1628 oasc.SolrCore.<init> [onenodecollectioncore] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1368676139162/onenodecollectioncore/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1368676135696/onenodecollection/
[junit4:junit4] 2> 490225 T1628 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@f45fa2e
[junit4:junit4] 2> 490226 T1628 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 490227 T1628 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1368676135696/onenodecollection
[junit4:junit4] 2> 490227 T1628 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1368676135696/onenodecollection/index/
[junit4:junit4] 2> 490228 T1628 oasc.SolrCore.initIndex WARN [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1368676135696/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 490229 T1628 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1368676135696/onenodecollection/index
[junit4:junit4] 2> 490230 T1628 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@addcbf4a lockFactory=org.apache.lucene.store.NativeFSLockFactory@217ecda7),segFN=segments_1,generation=1}
[junit4:junit4] 2> 490231 T1628 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 490233 T1628 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 490234 T1628 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 490234 T1628 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 490235 T1628 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 490236 T1628 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 490236 T1628 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 490237 T1628 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 490238 T1628 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 490238 T1628 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 490240 T1628 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 490242 T1628 oass.SolrIndexSearcher.<init> Opening Searcher@5c36c82f main
[junit4:junit4] 2> 490242 T1628 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1368676135696/onenodecollection/tlog
[junit4:junit4] 2> 490243 T1628 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 490244 T1628 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 490249 T1690 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@5c36c82f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 490252 T1628 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> ASYNC NEW_CORE C114 name=collection1 org.apache.solr.core.SolrCore@ade61a url=http://127.0.0.1:52325/collection1 node=127.0.0.1:52325_ C114_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:52325, state=active, node_name=127.0.0.1:52325_, collection=collection1, shard=shard1, core=collection1, leader=true}
[junit4:junit4] 2> 490296 T1630 C114 P52325 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 490296 T1629 C114 P52325 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&qt=/get&distrib=false&version=2&wt=javabin} status=0 QTime=165
[junit4:junit4] 2> 490298 T1630 C114 P52325 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6af7a869 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9d131394),segFN=segments_1,generation=1}
[junit4:junit4] 2> 490298 T1630 C114 P52325 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 490299 T1630 C114 P52325 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6af7a869 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9d131394),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6af7a869 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9d131394),segFN=segments_2,generation=2}
[junit4:junit4] 2> 490300 T1630 C114 P52325 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 490300 T1630 C114 P52325 oass.SolrIndexSearcher.<init> Opening Searcher@16b1c1a9 realtime
[junit4:junit4] 2> 490301 T1630 C114 P52325 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 490302 T1630 C114 P52325 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={softCommit=false&commit_end_point=true&commit=true&version=2&waitSearcher=true&wt=javabin&openSearcher=false} {commit=} 0 170
[junit4:junit4] 2> 490302 T1670 C112 P33247 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 490303 T1670 C112 P33247 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 490304 T1629 C114 P52325 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 490305 T1629 C114 P52325 oasc.SolrCore.execute [collection1] webapp= path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=2
[junit4:junit4] 2> 490305 T1670 C112 P33247 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 490305 T1670 C112 P33247 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 490306 T1670 C112 P33247 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 490307 T1630 C114 P52325 oasc.SolrCore.execute [collection1] webapp= path=/replication params={qt=/replication&version=2&generation=2&command=filelist&wt=javabin} status=0 QTime=0
[junit4:junit4] 2> 490308 T1670 C112 P33247 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 490309 T1670 C112 P33247 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty3/index.20130516054915054
[junit4:junit4] 2> 490309 T1670 C112 P33247 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@c6e0eeeb lockFactory=org.apache.lucene.store.NativeFSLockFactory@87a1289b) fullCopy=false
[junit4:junit4] 2> 490311 T1631 C114 P52325 oasc.SolrCore.execute [collection1] webapp= path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=segments_2&wt=filestream} status=0 QTime=1
[junit4:junit4] 2> 490312 T1670 C112 P33247 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 490312 T1670 C112 P33247 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 490313 T1670 C112 P33247 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 490314 T1670 C112 P33247 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2e9249c8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@ca973eb9),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2e9249c8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@ca973eb9),segFN=segments_2,generation=2}
[junit4:junit4] 2> 490314 T1670 C112 P33247 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 490314 T1670 C112 P33247 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 490315 T1670 C112 P33247 oass.SolrIndexSearcher.<init> Opening Searcher@aa71e58d main
[junit4:junit4] 2> 490316 T1669 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@aa71e58d main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 490316 T1670 C112 P33247 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty3/index.20130516054915054 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty3/index.20130516054915054;done=true>>]
[junit4:junit4] 2> 490317 T1670 C112 P33247 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty3/index.20130516054915054
[junit4:junit4] 2> 490317 T1670 C112 P33247 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty3/index.20130516054915054
[junit4:junit4] 2> 490317 T1670 C112 P33247 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 490318 T1670 C112 P33247 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 490318 T1670 C112 P33247 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 490318 T1670 C112 P33247 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 490319 T1670 C112 P33247 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 491002 T1616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 491003 T1616 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36186",
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:36186__collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:36186_",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 491006 T1616 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52325",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:52325_",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"onenodecollectioncore"}
[junit4:junit4] 2> 491006 T1616 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4] 2> 491007 T1616 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 491011 T1616 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:33247",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:33247__collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:33247_",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 491016 T1684 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> 491016 T1667 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> 491016 T1635 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> 491016 T1622 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> 491016 T1615 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> 491016 T1651 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> 491254 T1628 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4] 2> 491255 T1628 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:52325 collection:onenodecollection shard:shard1
[junit4:junit4] 2> 491256 T1628 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4] 2> 491261 T1628 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 491263 T1628 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 491264 T1628 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 491265 T1628 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52325/onenodecollectioncore/
[junit4:junit4] 2> 491266 T1628 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 491267 T1628 oasc.SyncStrategy.syncToMe http://127.0.0.1:52325/onenodecollectioncore/ has no replicas
[junit4:junit4] 2> 491267 T1628 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52325/onenodecollectioncore/
[junit4:junit4] 2> 491268 T1628 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4] 2> 491777 T1646 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:36186__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 491777 T1646 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={state=recovering&onlyIfLeader=true&checkLive=true&action=PREPRECOVERY&version=2&coreNodeName=127.0.0.1:36186__collection1&wt=javabin&nodeName=127.0.0.1:36186_&core=collection1} status=0 QTime=2002
[junit4:junit4] 2> 492523 T1616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 492529 T1615 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> 492529 T1667 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> 492529 T1635 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> 492529 T1622 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> 492529 T1684 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> 492529 T1651 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> 492576 T1628 oasc.ZkController.register We are http://127.0.0.1:52325/onenodecollectioncore/ and leader is http://127.0.0.1:52325/onenodecollectioncore/
[junit4:junit4] 2> 492576 T1628 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:52325
[junit4:junit4] 2> 492577 T1628 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 492577 T1628 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4] 2> 492579 T1628 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 492580 T1628 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1368676135696/onenodecollection&action=CREATE&version=2&numShards=1&name=onenodecollectioncore&wt=javabin&roles=none&collection=onenodecollection} status=0 QTime=2798
[junit4:junit4] 2> 492581 T1593 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4] 2> 492582 T1593 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 493584 T1593 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> C113_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:36186, state=recovering, node_name=127.0.0.1:36186_, collection=collection1, shard=shard2, core=collection1}
[junit4:junit4] 2> 493778 T1687 C113 P36186 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:44823/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 493779 T1687 C113 P36186 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:36186 START replicas=[http://127.0.0.1:44823/collection1/] nUpdates=100
[junit4:junit4] 2> 493780 T1687 C113 P36186 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 493780 T1687 C113 P36186 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 493781 T1687 C113 P36186 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 493781 T1687 C113 P36186 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 493782 T1687 C113 P36186 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 493782 T1687 C113 P36186 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:44823/collection1/. core=collection1
[junit4:junit4] 2> 493783 T1687 C113 P36186 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C115 name=collection1 org.apache.solr.core.SolrCore@de6db4a7 url=http://127.0.0.1:44823/collection1 node=127.0.0.1:44823_ C115_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:44823, state=active, node_name=127.0.0.1:44823_, collection=collection1, shard=shard2, core=collection1, leader=true}
[junit4:junit4] 2> 493788 T1646 C115 P44823 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&qt=/get&distrib=false&version=2&wt=javabin} status=0 QTime=0
[junit4:junit4] 2> 493793 T1647 C115 P44823 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 493794 T1647 C115 P44823 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@d5ad2ac6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@487cc5c9),segFN=segments_1,generation=1}
[junit4:junit4] 2> 493795 T1647 C115 P44823 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 493796 T1647 C115 P44823 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@d5ad2ac6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@487cc5c9),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@d5ad2ac6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@487cc5c9),segFN=segments_2,generation=2}
[junit4:junit4] 2> 493796 T1647 C115 P44823 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 493797 T1647 C115 P44823 oass.SolrIndexSearcher.<init> Opening Searcher@58b7c5e2 realtime
[junit4:junit4] 2> 493798 T1647 C115 P44823 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 493798 T1647 C115 P44823 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={softCommit=false&commit_end_point=true&commit=true&version=2&waitSearcher=true&wt=javabin&openSearcher=false} {commit=} 0 5
[junit4:junit4] 2> 493799 T1687 C113 P36186 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 493799 T1687 C113 P36186 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 493800 T1644 C115 P44823 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 493801 T1644 C115 P44823 oasc.SolrCore.execute [collection1] webapp= path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 493802 T1687 C113 P36186 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 493802 T1687 C113 P36186 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 493802 T1687 C113 P36186 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 493804 T1646 C115 P44823 oasc.SolrCore.execute [collection1] webapp= path=/replication params={qt=/replication&version=2&generation=2&command=filelist&wt=javabin} status=0 QTime=0
[junit4:junit4] 2> 493804 T1687 C113 P36186 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 493805 T1687 C113 P36186 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty4/index.20130516054918551
[junit4:junit4] 2> 493805 T1687 C113 P36186 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@b118aca1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@f47b5785) fullCopy=false
[junit4:junit4] 2> 493807 T1647 C115 P44823 oasc.SolrCore.execute [collection1] webapp= path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=segments_2&wt=filestream} status=0 QTime=0
[junit4:junit4] 2> 493808 T1687 C113 P36186 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 493809 T1687 C113 P36186 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 493809 T1687 C113 P36186 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 493810 T1687 C113 P36186 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@60e970e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@eafd0694),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@60e970e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@eafd0694),segFN=segments_2,generation=2}
[junit4:junit4] 2> 493810 T1687 C113 P36186 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 493811 T1687 C113 P36186 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 493811 T1687 C113 P36186 oass.SolrIndexSearcher.<init> Opening Searcher@3f2b324 main
[junit4:junit4] 2> 493812 T1686 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3f2b324 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 493812 T1687 C113 P36186 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty4/index.20130516054918551 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty4/index.20130516054918551;done=true>>]
[junit4:junit4] 2> 493813 T1687 C113 P36186 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty4/index.20130516054918551
[junit4:junit4] 2> 493813 T1687 C113 P36186 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty4/index.20130516054918551
[junit4:junit4] 2> 493813 T1687 C113 P36186 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 493813 T1687 C113 P36186 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 493814 T1687 C113 P36186 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 493814 T1687 C113 P36186 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 493817 T1687 C113 P36186 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 494034 T1616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 494035 T1616 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52325",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:52325__onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:52325_",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"onenodecollectioncore"}
[junit4:junit4] 2> 494037 T1616 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36186",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:36186__collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:36186_",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 494040 T1667 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> 494040 T1684 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> 494040 T1635 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> 494040 T1622 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> 494040 T1615 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> 494040 T1651 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> 494586 T1593 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 494587 T1593 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4] 2> 494587 T1593 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 494594 T1593 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 494595 T1695 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d984c766 name:ZooKeeperConnection Watcher:127.0.0.1:41830 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 494595 T1593 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 494638 T1593 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 60339
[junit4:junit4] 2> 494638 T1593 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=406827390
[junit4:junit4] 2> 495546 T1616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 495547 T1616 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:60339",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:60339__collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:60339_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 495551 T1667 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> 495551 T1684 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> 495551 T1635 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> 495551 T1615 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> 495551 T1651 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> 496640 T1593 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 496641 T1593 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 496643 T1593 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@bb8142bb
[junit4:junit4] 2> 496646 T1593 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 496646 T1593 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 496647 T1593 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 496647 T1593 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 496648 T1593 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 496648 T1593 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 496649 T1593 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/control/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/control/data/index;done=false>>]
[junit4:junit4] 2> 496649 T1593 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/control/data/index
[junit4:junit4] 2> 496650 T1593 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/control/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/control/data;done=false>>]
[junit4:junit4] 2> 496650 T1593 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/control/data
[junit4:junit4] 2> 496651 T1616 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89697559229169667-127.0.0.1:60339_-n_0000000000) am no longer a leader.
[junit4:junit4] 2> 496652 T1651 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 496652 T1667 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 496652 T1615 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 496652 T1615 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 496652 T1595 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13eab7473130003, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:780)
[junit4:junit4] 2>
[junit4:junit4] 2> 496653 T1615 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 496654 T1684 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 496654 T1635 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 496654 T1684 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 496654 T1635 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 496655 T1667 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 496655 T1651 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 496657 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 496659 T1635 oasc.Overseer.start Overseer (id=89697559229169670-127.0.0.1:52325_-n_0000000001) starting
[junit4:junit4] 2> 496663 T1697 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 496664 T1696 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 496665 T1696 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 496666 T1696 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:60339",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:60339__collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:60339_",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 496670 T1667 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 496670 T1651 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 496670 T1684 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 496670 T1635 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 496672 T1593 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 496725 T1593 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 52325
[junit4:junit4] 2> 496726 T1593 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=258034597
[junit4:junit4] 2> 498175 T1696 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 498177 T1696 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52325",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:52325__onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:52325_",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"onenodecollectioncore"}
[junit4:junit4] 2> 498181 T1696 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52325",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:52325__collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:52325_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 498185 T1667 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 498185 T1684 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 498185 T1651 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 498185 T1635 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 499731 T1593 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 499731 T1593 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 499734 T1593 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> 499735 T1593 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@ade61a
[junit4:junit4] 2> 499739 T1593 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 499740 T1593 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 499741 T1593 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 499742 T1593 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 499744 T1593 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 499745 T1593 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 499746 T1593 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty1 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty1;done=false>>]
[junit4:junit4] 2> 499747 T1593 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty1
[junit4:junit4] 2> 499749 T1593 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty1/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty1/index;done=false>>]
[junit4:junit4] 2> 499750 T1593 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty1/index
[junit4:junit4] 2> 499751 T1593 oasc.SolrCore.close [onenodecollectioncore] CLOSING SolrCore org.apache.solr.core.SolrCore@b94ca172
[junit4:junit4] 2> 499756 T1593 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 499757 T1593 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 499757 T1593 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 499758 T1593 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 499758 T1593 oasc.SolrCore.closeSearcher [onenodecollectioncore] Closing main searcher on request.
[junit4:junit4] 2> 499759 T1593 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 499759 T1593 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1368676135696/onenodecollection/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1368676135696/onenodecollection/index;done=false>>]
[junit4:junit4] 2> 499760 T1593 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1368676135696/onenodecollection/index
[junit4:junit4] 2> 499760 T1593 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1368676135696/onenodecollection [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1368676135696/onenodecollection;done=false>>]
[junit4:junit4] 2> 499761 T1593 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1368676135696/onenodecollection
[junit4:junit4] 2> 499762 T1696 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89697559229169670-127.0.0.1:52325_-n_0000000001) am no longer a leader.
[junit4:junit4] 2> 499763 T1667 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 499764 T1684 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 499764 T1651 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 499764 T1684 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 499764 T1667 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 499766 T1651 oasc.Overseer.start Overseer (id=89697559229169672-127.0.0.1:44823_-n_0000000002) starting
[junit4:junit4] 2> 499767 T1667 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 499768 T1667 oasc.ShardLeaderElectionContext.shouldIBeLeader Checking if I should try and be the leader.
[junit4:junit4] 2> 499769 T1667 oasc.ShardLeaderElectionContext.shouldIBeLeader My last published State was Active, it's okay to be the leader.
[junit4:junit4] 2> 499769 T1667 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 499769 T1651 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 499769 T1667 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:33247/collection1/
[junit4:junit4] 2> 499770 T1698 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 499770 T1667 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 499769 T1699 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 499771 T1651 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 499770 T1667 oasc.SyncStrategy.syncToMe http://127.0.0.1:33247/collection1/ has no replicas
[junit4:junit4] 2> 499771 T1667 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:33247/collection1/
[junit4:junit4] 2> 499772 T1667 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 499772 T1698 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 499772 T1698 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52325",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:52325__collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:52325_",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 499775 T1698 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52325",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:52325__onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:52325_",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"onenodecollectioncore"}
[junit4:junit4] 2> 499783 T1667 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 499783 T1684 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 499783 T1651 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 499784 T1593 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 499837 T1593 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 44823
[junit4:junit4] 2> 499837 T1593 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1516863868
[junit4:junit4] 2> 500839 T1593 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 500839 T1593 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 500841 T1593 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@de6db4a7
[junit4:junit4] 2> 500844 T1593 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 500844 T1593 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 500845 T1593 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 500845 T1593 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 500846 T1593 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 500847 T1593 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 500847 T1593 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty2/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty2/index;done=false>>]
[junit4:junit4] 2> 500848 T1593 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty2/index
[junit4:junit4] 2> 500848 T1593 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty2 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty2;done=false>>]
[junit4:junit4] 2> 500849 T1593 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty2
[junit4:junit4] 2> 500849 T1698 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89697559229169672-127.0.0.1:44823_-n_0000000002) am no longer a leader.
[junit4:junit4] 2> 500850 T1651 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 500850 T1667 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 500851 T1684 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 500851 T1684 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 500852 T1667 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 500853 T1684 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 500853 T1667 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 500854 T1684 oasc.ShardLeaderElectionContext.shouldIBeLeader Checking if I should try and be the leader.
[junit4:junit4] 2> 500855 T1667 oasc.Overseer.start Overseer (id=89697559229169674-127.0.0.1:33247_-n_0000000003) starting
[junit4:junit4] 2> 500855 T1684 oasc.ShardLeaderElectionContext.shouldIBeLeader My last published State was Active, it's okay to be the leader.
[junit4:junit4] 2> 500856 T1684 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 500856 T1684 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:36186/collection1/
[junit4:junit4] 2> 500856 T1684 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 500857 T1684 oasc.SyncStrategy.syncToMe http://127.0.0.1:36186/collection1/ has no replicas
[junit4:junit4] 2> 500857 T1684 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:36186/collection1/
[junit4:junit4] 2> 500858 T1684 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 500858 T1701 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 500858 T1700 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 500860 T1700 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 500861 T1700 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44823",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:44823__collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:44823_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 500863 T1700 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44823",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:44823__collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:44823_",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 500869 T1667 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 500869 T1684 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 500872 T1593 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 500925 T1593 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 33247
[junit4:junit4] 2> 500925 T1593 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=2081907553
[junit4:junit4] 2> 501063 T1635 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 501064 T1635 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 501064 T1635 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 501928 T1593 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 501929 T1593 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 501931 T1593 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@c9100bb6
[junit4:junit4] 2> 501937 T1593 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 501939 T1593 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 501940 T1593 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 501941 T1593 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 501943 T1593 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 501944 T1593 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 501945 T1593 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty3/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty3/index;done=false>>]
[junit4:junit4] 2> 501946 T1593 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty3/index
[junit4:junit4] 2> 501946 T1593 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty3 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty3;done=false>>]
[junit4:junit4] 2> 501947 T1593 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty3
[junit4:junit4] 2> 501949 T1700 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89697559229169674-127.0.0.1:33247_-n_0000000003) am no longer a leader.
[junit4:junit4] 2> 501950 T1667 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 501950 T1667 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 501951 T1667 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 501951 T1684 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 501954 T1684 oasc.Overseer.start Overseer (id=89697559229169676-127.0.0.1:36186_-n_0000000004) starting
[junit4:junit4] 2> 501960 T1703 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 501960 T1684 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4:junit4] 2> 501961 T1684 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> 501961 T1702 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 501963 T1702 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 501964 T1702 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:33247",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:33247__collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:33247_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 501969 T1702 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:33247",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:33247__collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:33247_",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 501971 T1593 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 501974 T1684 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 502023 T1593 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 36186
[junit4:junit4] 2> 502024 T1593 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1942710571
[junit4:junit4] 2> 502150 T1651 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 502151 T1651 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 503027 T1593 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 503027 T1593 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 503029 T1593 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@e0298c43
[junit4:junit4] 2> 503034 T1593 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 503034 T1593 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 503035 T1593 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 503035 T1593 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 503036 T1593 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 503037 T1593 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 503037 T1593 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty4 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty4;done=false>>]
[junit4:junit4] 2> 503038 T1593 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty4
[junit4:junit4] 2> 503038 T1593 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty4/index;done=false>>]
[junit4:junit4] 2> 503039 T1593 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1368676135696/jetty4/index
[junit4:junit4] 2> 503039 T1702 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89697559229169676-127.0.0.1:36186_-n_0000000004) am no longer a leader.
[junit4:junit4] 2> 503061 T1593 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 503121 T1593 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 503124 T1593 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:41830 41830
[junit4:junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4] 1> / (2)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1> /solr (7)
[junit4:junit4] 1> /solr/configs (1)
[junit4:junit4] 1> /solr/configs/conf1 (9)
[junit4:junit4] 1> /solr/configs/conf1/old_synonyms.txt (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/protwords.txt (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/stopwords.txt (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/synonyms.txt (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/schema.xml (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/currency.xml (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/open-exchange-rates.json (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "disclaimer": "This data is not real, it was synthetically created to match currency.xml. It is modeled after the data format available from openexchangerates.org. See https://openexchangerates.org/documentation for details",
[junit4:junit4] 1> "license": "http://www.apache.org/licenses/LICENSE-2.0",
[junit4:junit4] 1> "timestamp": 1332070464,
[junit4:junit4] 1>
[junit4:junit4] 1>
[junit4:junit4] 1> "IMPORTANT NOTE": "In order for tests to work, this data must be kept in sync with ./currency.xml",
[junit4:junit4] 1>
[junit4:junit4] 1>
[junit4:junit4] 1> "base": "USD",
[junit4:junit4] 1> "rates": {
[junit4:junit4] 1> "USD": 1,
[junit4:junit4] 1> "JPY": 81.29,
[junit4:junit4] 1> "EUR": 2.5,
[junit4:junit4] 1> "GBP": 0.5,
[junit4:junit4] 1> "MXN": 2.0
[junit4:junit4] 1> }
[junit4:junit4] 1> }
[junit4:junit4] 1>
[junit4:junit4] 1> /solr/configs/conf1/solrconfig.xml (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/mapping-ISOLatin1Accent.txt (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/overseer (3)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1> /solr/overseer/queue (0)
[junit4:junit4] 1> /solr/overseer/collection-queue-work (0)
[junit4:junit4] 1> /solr/overseer/queue-work (0)
[junit4:junit4] 1> /solr/overseer_elect (2)
[junit4:junit4] 1> /solr/overseer_elect/leader (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"id":"89697559229169667-127.0.0.1:60339_-n_0000000000"}
[junit4:junit4] 1> /solr/overseer_elect/election (5)
[junit4:junit4] 1> /solr/overseer_elect/election/89697559229169672-127.0.0.1:44823_-n_0000000002 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89697559229169676-127.0.0.1:36186_-n_0000000004 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89697559229169667-127.0.0.1:60339_-n_0000000000 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89697559229169670-127.0.0.1:52325_-n_0000000001 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89697559229169674-127.0.0.1:33247_-n_0000000003 (0)
[junit4:junit4] 1> /solr/collections (3)
[junit4:junit4] 1> /solr/collections/control_collection (3)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"configName":"conf1"}
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect (1)
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect/shard1 (1)
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election (1)
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election/89697559229169667-127.0.0.1:60339__collection1-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/control_collection/leaders (1)
[junit4:junit4] 1> /solr/collections/control_collection/leaders/shard1 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "base_url":"http://127.0.0.1:60339",
[junit4:junit4] 1> "node_name":"127.0.0.1:60339_",
[junit4:junit4] 1> "core":"collection1"}
[junit4:junit4] 1> /solr/collections/control_collection/shards (0)
[junit4:junit4] 1> /solr/collections/collection1 (3)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"configName":"conf1"}
[junit4:junit4] 1> /solr/collections/collection1/leader_elect (2)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1 (1)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election (2)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/89697559229169670-127.0.0.1:52325__collection1-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/89697559229169674-127.0.0.1:33247__collection1-n_0000000001 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2 (1)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2/election (2)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2/election/89697559229169676-127.0.0.1:36186__collection1-n_0000000001 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2/election/89697559229169672-127.0.0.1:44823__collection1-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/collection1/leaders (2)
[junit4:junit4] 1> /solr/collections/collection1/leaders/shard1 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "base_url":"http://127.0.0.1:52325",
[junit4:junit4] 1> "node_name":"127.0.0.1:52325_",
[junit4:junit4] 1> "core":"collection1"}
[junit4:junit4] 1> /solr/collections/collection1/leaders/shard2 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "base_url":"http://127.0.0.1:44823",
[junit4:junit4] 1> "node_name":"127.0.0.1:44823_",
[junit4:junit4] 1> "core":"collection1"}
[junit4:junit4] 1> /solr/collections/collection1/shards (0)
[junit4:junit4] 1> /solr/collections/onenodecollection (2)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "router":"compositeId",
[junit4:junit4] 1> "configName":"conf1"}
[junit4:junit4] 1> /solr/collections/onenodecollection/leader_elect (1)
[junit4:junit4] 1> /solr/collections/onenodecollection/leader_elect/shard1 (1)
[junit4:junit4] 1> /solr/collections/onenodecollection/leader_elect/shard1/election (1)
[junit4:junit4] 1> /solr/collections/onenodecollection/leader_elect/shard1/election/89697559229169670-127.0.0.1:52325__onenodecollectioncore-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/onenodecollection/leaders (1)
[junit4:junit4] 1> /solr/collections/onenodecollection/leaders/shard1 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "base_url":"http://127.0.0.1:52325",
[junit4:junit4] 1> "node_name":"127.0.0.1:52325_",
[junit4:junit4] 1> "core":"onenodecollectioncore"}
[junit4:junit4] 1> /solr/aliases.json (0)
[junit4:junit4] 1> /solr/live_nodes (5)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:36186_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:44823_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:52325_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:60339_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:33247_ (0)
[junit4:junit4] 1> /solr/clusterstate.json (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "control_collection":{
[junit4:junit4] 1> "shards":{"shard1":{
[junit4:junit4] 1> "range":"80000000-7fffffff",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "replicas":{"127.0.0.1:60339__collection1":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:60339",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:60339_",
[junit4:junit4] 1> "collection":"control_collection",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "leader":"true"}}}},
[junit4:junit4] 1> "router":"compositeId"},
[junit4:junit4] 1> "onenodecollection":{
[junit4:junit4] 1> "shards":{"shard1":{
[junit4:junit4] 1> "range":"80000000-7fffffff",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "replicas":{"127.0.0.1:52325__onenodecollectioncore":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:52325",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:52325_",
[junit4:junit4] 1> "roles":"none",
[junit4:junit4] 1> "collection":"onenodecollection",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "core":"onenodecollectioncore",
[junit4:junit4] 1> "leader":"true"}}}},
[junit4:junit4] 1> "router":"compositeId"},
[junit4:junit4] 1> "collection1":{
[junit4:junit4] 1> "shards":{
[junit4:junit4] 1> "shard1":{
[junit4:junit4] 1> "range":"80000000-ffffffff",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "replicas":{
[junit4:junit4] 1> "127.0.0.1:52325__collection1":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:52325",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:52325_",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "leader":"true"},
[junit4:junit4] 1> "127.0.0.1:33247__collection1":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:33247",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:33247_",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "core":"collection1"}}},
[junit4:junit4] 1> "shard2":{
[junit4:junit4] 1> "range":"0-7fffffff",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "replicas":{
[junit4:junit4] 1> "127.0.0.1:44823__collection1":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:44823",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:44823_",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "shard":"shard2",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "leader":"true"},
[junit4:junit4] 1> "127.0.0.1:36186__collection1":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:36186",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:36186_",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "shard":"shard2",
[junit4:junit4] 1> "core":"collection1"}}}},
[junit4:junit4] 1> "router":"compositeId"}}
[junit4:junit4] 1> /zookeeper (1)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1>
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZk2Test -Dtests.method=testDistribSearch -Dtests.seed=F21F84F2B0C5589B -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_PY -Dtests.timezone=Europe/Rome -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] ERROR 32.2s J0 | BasicDistributedZk2Test.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:44823/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([F21F84F2B0C5589B:73F90AEAC79A38A7]:0)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4:junit4] > at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
[junit4:junit4] > at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
[junit4:junit4] > at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
[junit4:junit4] > at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:198)
[junit4:junit4] > at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:90)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:780)
[junit4:junit4] 2> 503152 T1593 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 32210 T1592 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4] 2> 504340 T1684 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 504341 T1684 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> 504341 T1684 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=es_PY, timezone=Europe/Rome
[junit4:junit4] 2> NOTE: Linux 3.2.0-41-generic x86/IBM Corporation 1.7.0 (32-bit)/cpus=8,threads=1,free=72871384,total=213647360
[junit4:junit4] 2> NOTE: All tests run in this JVM: [LukeRequestHandlerTest, TestFastLRUCache, TestDocSet, AlternateDirectoryTest, MoreLikeThisHandlerTest, TestDynamicFieldResource, DistributedTermsComponentTest, TestFaceting, TestExtendedDismaxParser, SliceStateUpdateTest, TestSolrQueryParser, LegacyHTMLStripCharFilterTest, SOLR749Test, TestDocumentBuilder, TestStressRecovery, JsonLoaderTest, TestRemoteStreaming, PreAnalyzedFieldTest, ChaosMonkeyNothingIsSafeTest, TermVectorComponentTest, SchemaVersionSpecificBehaviorTest, SliceStateTest, TestXIncludeConfig, TestTrie, ExternalFileFieldSortTest, SpellingQueryConverterTest, SoftAutoCommitTest, TestSolrDeletionPolicy2, UpdateRequestProcessorFactoryTest, TestPseudoReturnFields, OverseerCollectionProcessorTest, BinaryUpdateRequestHandlerTest, TestWriterPerf, PluginInfoTest, TestSurroundQueryParser, DistributedSpellCheckComponentTest, BasicFunctionalityTest, TestIBSimilarityFactory, SolrIndexSplitterTest, FieldMutatingUpdateProcessorTest, TestSort, SyncSliceTest, SystemInfoHandlerTest, SolrInfoMBeanTest, TestDefaultSearchFieldResource, TestRealTimeGet, TestCoreContainer, BasicDistributedZkTest, LoggingHandlerTest, TestSolrDeletionPolicy1, CSVRequestHandlerTest, TestSolrQueryParserDefaultOperatorResource, SimpleFacetsTest, DocValuesTest, TestClassNameShortening, BadCopyFieldTest, TestPerFieldSimilarity, SolrTestCaseJ4Test, SolrCoreTest, TestSolrCoreProperties, FileBasedSpellCheckerTest, TestCloudManagedSchema, TestManagedSchemaFieldResource, SpatialFilterTest, TestFunctionQuery, QueryParsingTest, PolyFieldTest, SuggesterFSTTest, TestMaxScoreQueryParser, ShowFileRequestHandlerTest, ResourceLoaderTest, RAMDirectoryFactoryTest, BasicDistributedZk2Test]
[junit4:junit4] Completed on J0 in 33.48s, 1 test, 1 error <<< FAILURES!
[...truncated 544 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:377: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:370: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:437: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1240: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:884: There were test failures: 295 suites, 1231 tests, 1 error, 14 ignored (8 assumptions)
Total time: 41 minutes 16 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure