You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/06/09 19:02:07 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/ibm-j9-jdk7) - Build # 5990
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/5990/
Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
1 tests failed.
FAILED: org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch
Error Message:
Server at http://127.0.0.1:45333/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:45333/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
at __randomizedtesting.SeedInfo.seed([1A716F651BA0B9AB:9B97E17D6CFFD997]: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 9512 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4] 2> 215080 T716 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 215087 T716 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1370796259321
[junit4:junit4] 2> 215088 T716 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 215089 T717 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 215189 T716 oasc.ZkTestServer.run start zk server on port:57311
[junit4:junit4] 2> 215191 T716 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 215197 T723 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26249691 name:ZooKeeperConnection Watcher:127.0.0.1:57311 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 215198 T716 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 215198 T716 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 215201 T716 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 215202 T725 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bf548abb name:ZooKeeperConnection Watcher:127.0.0.1:57311/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 215203 T716 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 215203 T716 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 215206 T716 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 215209 T716 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 215212 T716 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 215215 T716 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 215215 T716 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 215219 T716 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 215220 T716 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 215223 T716 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 215224 T716 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 215227 T716 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 215228 T716 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 215230 T716 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 215231 T716 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 215234 T716 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 215235 T716 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 215237 T716 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 215238 T716 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 215241 T716 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 215242 T716 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 215245 T716 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 215246 T716 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 215357 T716 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 215361 T716 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:35447
[junit4:junit4] 2> 215362 T716 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 215362 T716 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 215363 T716 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1370796259482
[junit4:junit4] 2> 215364 T716 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1370796259482/solr.xml
[junit4:junit4] 2> 215364 T716 oasc.CoreContainer.<init> New CoreContainer 292785768
[junit4:junit4] 2> 215365 T716 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1370796259482/'
[junit4:junit4] 2> 215365 T716 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1370796259482/'
[junit4:junit4] 2> 215404 T716 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 215405 T716 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 215406 T716 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 215406 T716 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 215407 T716 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 215407 T716 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 215408 T716 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 215409 T716 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 215409 T716 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 215410 T716 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 215415 T716 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 215416 T716 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57311/solr
[junit4:junit4] 2> 215417 T716 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 215418 T716 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 215419 T736 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@27f72c0f name:ZooKeeperConnection Watcher:127.0.0.1:57311 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 215420 T716 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 215421 T716 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 215426 T716 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 215427 T738 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f49fcb57 name:ZooKeeperConnection Watcher:127.0.0.1:57311/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 215428 T716 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 215429 T716 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 215431 T716 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 215433 T716 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 215435 T716 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35447_
[junit4:junit4] 2> 215436 T716 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35447_
[junit4:junit4] 2> 215438 T716 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 215442 T716 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 215444 T716 oasc.Overseer.start Overseer (id=89836503651057667-127.0.0.1:35447_-n_0000000000) starting
[junit4:junit4] 2> 215446 T716 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 215449 T740 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 215449 T716 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 215451 T716 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 215452 T716 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 215454 T739 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 215457 T741 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1370796259482/collection1
[junit4:junit4] 2> 215457 T741 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 215457 T741 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 215458 T741 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 215458 T741 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1370796259482/collection1/'
[junit4:junit4] 2> 215459 T741 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1370796259482/collection1/lib/README' to classloader
[junit4:junit4] 2> 215460 T741 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1370796259482/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 215483 T741 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 215521 T741 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 215522 T741 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 215529 T741 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 215855 T741 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 215859 T741 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 215862 T741 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 215871 T741 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 215875 T741 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 215879 T741 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 215880 T741 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 215880 T741 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 215881 T741 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 215882 T741 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 215882 T741 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 215882 T741 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 215883 T741 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1370796259482/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/control/data/
[junit4:junit4] 2> 215883 T741 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2621281d
[junit4:junit4] 2> 215884 T741 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 215884 T741 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/control/data
[junit4:junit4] 2> 215885 T741 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/control/data/index/
[junit4:junit4] 2> 215885 T741 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 215885 T741 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/control/data/index
[junit4:junit4] 2> 215887 T741 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@ed9c794c lockFactory=org.apache.lucene.store.NativeFSLockFactory@105dc5f5),segFN=segments_1,generation=1}
[junit4:junit4] 2> 215887 T741 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 215889 T741 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 215889 T741 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 215890 T741 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 215890 T741 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 215891 T741 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 215891 T741 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 215891 T741 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 215892 T741 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 215892 T741 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 215893 T741 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 215895 T741 oass.SolrIndexSearcher.<init> Opening Searcher@36a866bf main
[junit4:junit4] 2> 215896 T741 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/control/data/tlog
[junit4:junit4] 2> 215896 T741 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 215897 T741 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 215900 T742 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@36a866bf main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 215900 T741 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 215901 T741 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 216958 T739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 216959 T739 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:35447",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "node_name":"127.0.0.1:35447_",
[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> 216960 T739 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 216960 T739 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 216965 T738 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> 217902 T741 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 217903 T741 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:35447 collection:control_collection shard:shard1
[junit4:junit4] 2> 217903 T741 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 217909 T741 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 217911 T741 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 217912 T741 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 217912 T741 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:35447/collection1/
[junit4:junit4] 2> 217912 T741 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 217913 T741 oasc.SyncStrategy.syncToMe http://127.0.0.1:35447/collection1/ has no replicas
[junit4:junit4] 2> 217913 T741 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:35447/collection1/
[junit4:junit4] 2> 217913 T741 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 218470 T739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 218477 T738 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> 218519 T741 oasc.ZkController.register We are http://127.0.0.1:35447/collection1/ and leader is http://127.0.0.1:35447/collection1/
[junit4:junit4] 2> 218520 T741 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35447
[junit4:junit4] 2> 218520 T741 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 218520 T741 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 218521 T741 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 218522 T741 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 218523 T716 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 218524 T716 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 218525 T716 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 218533 T716 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 218535 T716 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 218536 T745 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8c4fc4e5 name:ZooKeeperConnection Watcher:127.0.0.1:57311/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 218537 T716 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 218538 T716 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 218540 T716 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 218622 T716 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 218624 T716 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51655
[junit4:junit4] 2> 218625 T716 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 218626 T716 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 218626 T716 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370796262774
[junit4:junit4] 2> 218627 T716 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370796262774/solr.xml
[junit4:junit4] 2> 218627 T716 oasc.CoreContainer.<init> New CoreContainer 1498582499
[junit4:junit4] 2> 218628 T716 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370796262774/'
[junit4:junit4] 2> 218629 T716 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370796262774/'
[junit4:junit4] 2> 218667 T716 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 218668 T716 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 218668 T716 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 218669 T716 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 218669 T716 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 218670 T716 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 218671 T716 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 218671 T716 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 218672 T716 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 218672 T716 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 218677 T716 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 218678 T716 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57311/solr
[junit4:junit4] 2> 218679 T716 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 218680 T716 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 218681 T756 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8a7738c name:ZooKeeperConnection Watcher:127.0.0.1:57311 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 218681 T716 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 218683 T716 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 218689 T716 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 218690 T758 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c212bf41 name:ZooKeeperConnection Watcher:127.0.0.1:57311/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 218690 T716 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 218693 T716 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 219696 T716 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51655_
[junit4:junit4] 2> 219697 T716 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51655_
[junit4:junit4] 2> 219700 T738 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 219700 T745 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 219700 T738 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> 219700 T758 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 219704 T759 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370796262774/collection1
[junit4:junit4] 2> 219704 T759 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 219705 T759 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 219705 T759 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 219706 T759 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370796262774/collection1/'
[junit4:junit4] 2> 219707 T759 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370796262774/collection1/lib/README' to classloader
[junit4:junit4] 2> 219708 T759 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370796262774/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 219732 T759 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 219762 T759 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 219763 T759 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 219767 T759 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 219982 T739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 219983 T739 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:35447",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "node_name":"127.0.0.1:35447_",
[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> 219986 T738 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> 219986 T745 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> 219987 T758 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> 220091 T759 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 220095 T759 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 220098 T759 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 220108 T759 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 220112 T759 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 220116 T759 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 220117 T759 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 220117 T759 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 220117 T759 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 220118 T759 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 220119 T759 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 220119 T759 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 220119 T759 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370796262774/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty1/
[junit4:junit4] 2> 220120 T759 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2621281d
[junit4:junit4] 2> 220120 T759 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 220121 T759 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty1
[junit4:junit4] 2> 220121 T759 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty1/index/
[junit4:junit4] 2> 220121 T759 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 220122 T759 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty1/index
[junit4:junit4] 2> 220124 T759 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@48d97b5b lockFactory=org.apache.lucene.store.NativeFSLockFactory@aee28c5f),segFN=segments_1,generation=1}
[junit4:junit4] 2> 220124 T759 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 220125 T759 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 220126 T759 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 220126 T759 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 220127 T759 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 220128 T759 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 220128 T759 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 220128 T759 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 220129 T759 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 220129 T759 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 220130 T759 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 220132 T759 oass.SolrIndexSearcher.<init> Opening Searcher@264b262c main
[junit4:junit4] 2> 220133 T759 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty1/tlog
[junit4:junit4] 2> 220134 T759 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 220134 T759 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 220137 T760 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@264b262c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 220139 T759 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 220139 T759 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 221489 T739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 221490 T739 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:51655",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "node_name":"127.0.0.1:51655_",
[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> 221491 T739 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 221491 T739 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 221495 T758 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> 221495 T745 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> 221496 T738 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> 222140 T759 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 222141 T759 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51655 collection:collection1 shard:shard1
[junit4:junit4] 2> 222142 T759 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 222148 T759 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 222150 T759 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 222150 T759 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 222151 T759 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51655/collection1/
[junit4:junit4] 2> 222151 T759 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 222151 T759 oasc.SyncStrategy.syncToMe http://127.0.0.1:51655/collection1/ has no replicas
[junit4:junit4] 2> 222152 T759 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51655/collection1/
[junit4:junit4] 2> 222152 T759 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 223000 T739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 223005 T738 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> 223005 T745 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> 223005 T758 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> 223010 T759 oasc.ZkController.register We are http://127.0.0.1:51655/collection1/ and leader is http://127.0.0.1:51655/collection1/
[junit4:junit4] 2> 223010 T759 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51655
[junit4:junit4] 2> 223010 T759 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 223011 T759 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 223011 T759 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 223013 T759 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 223014 T716 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 223015 T716 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 223016 T716 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 223100 T716 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 223102 T716 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:45333
[junit4:junit4] 2> 223103 T716 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 223104 T716 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 223104 T716 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1370796267256
[junit4:junit4] 2> 223105 T716 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1370796267256/solr.xml
[junit4:junit4] 2> 223106 T716 oasc.CoreContainer.<init> New CoreContainer -4144296
[junit4:junit4] 2> 223106 T716 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1370796267256/'
[junit4:junit4] 2> 223107 T716 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1370796267256/'
[junit4:junit4] 2> 223155 T716 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 223155 T716 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 223156 T716 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 223157 T716 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 223157 T716 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 223158 T716 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 223158 T716 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 223159 T716 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 223160 T716 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 223160 T716 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 223165 T716 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 223166 T716 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57311/solr
[junit4:junit4] 2> 223167 T716 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 223168 T716 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 223169 T772 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@99780ba5 name:ZooKeeperConnection Watcher:127.0.0.1:57311 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 223170 T716 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 223171 T716 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 223177 T716 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 223178 T774 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a5aed0be name:ZooKeeperConnection Watcher:127.0.0.1:57311/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 223179 T716 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 223181 T716 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 224184 T716 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45333_
[junit4:junit4] 2> 224185 T716 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45333_
[junit4:junit4] 2> 224187 T758 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> 224188 T745 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 224188 T738 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 224188 T745 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> 224188 T738 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> 224188 T758 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 224188 T774 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 224192 T775 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1370796267256/collection1
[junit4:junit4] 2> 224192 T775 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 224193 T775 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 224193 T775 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 224194 T775 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1370796267256/collection1/'
[junit4:junit4] 2> 224195 T775 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1370796267256/collection1/lib/README' to classloader
[junit4:junit4] 2> 224195 T775 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1370796267256/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 224221 T775 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 224253 T775 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 224254 T775 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 224261 T775 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 224510 T739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 224510 T739 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:51655",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "node_name":"127.0.0.1:51655_",
[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> 224514 T758 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> 224514 T745 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> 224514 T774 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> 224514 T738 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> 224578 T775 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 224582 T775 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 224585 T775 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 224599 T775 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 224603 T775 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 224607 T775 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 224608 T775 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 224608 T775 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 224609 T775 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 224610 T775 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 224610 T775 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 224610 T775 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 224611 T775 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1370796267256/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty2/
[junit4:junit4] 2> 224611 T775 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2621281d
[junit4:junit4] 2> 224611 T775 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 224612 T775 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty2
[junit4:junit4] 2> 224612 T775 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty2/index/
[junit4:junit4] 2> 224613 T775 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 224613 T775 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty2/index
[junit4:junit4] 2> 224614 T775 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@74618f80 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3a5a2223),segFN=segments_1,generation=1}
[junit4:junit4] 2> 224615 T775 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 224616 T775 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 224617 T775 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 224617 T775 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 224618 T775 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 224618 T775 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 224619 T775 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 224619 T775 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 224619 T775 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 224620 T775 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 224621 T775 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 224623 T775 oass.SolrIndexSearcher.<init> Opening Searcher@7aad1fde main
[junit4:junit4] 2> 224623 T775 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty2/tlog
[junit4:junit4] 2> 224624 T775 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 224624 T775 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 224629 T776 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7aad1fde main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 224630 T775 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 224630 T775 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 226019 T739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 226020 T739 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:45333",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "node_name":"127.0.0.1:45333_",
[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> 226020 T739 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 226020 T739 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 226024 T758 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> 226024 T774 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> 226024 T738 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> 226024 T745 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> 226632 T775 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 226632 T775 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:45333 collection:collection1 shard:shard2
[junit4:junit4] 2> 226633 T775 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 226647 T775 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 226650 T775 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 226650 T775 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 226650 T775 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:45333/collection1/
[junit4:junit4] 2> 226651 T775 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 226651 T775 oasc.SyncStrategy.syncToMe http://127.0.0.1:45333/collection1/ has no replicas
[junit4:junit4] 2> 226651 T775 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:45333/collection1/
[junit4:junit4] 2> 226652 T775 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 227529 T739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 227535 T758 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> 227535 T774 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> 227535 T745 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> 227535 T738 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> 227558 T775 oasc.ZkController.register We are http://127.0.0.1:45333/collection1/ and leader is http://127.0.0.1:45333/collection1/
[junit4:junit4] 2> 227559 T775 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:45333
[junit4:junit4] 2> 227559 T775 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 227560 T775 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 227560 T775 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 227562 T775 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 227563 T716 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 227565 T716 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 227567 T716 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 227644 T716 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 227646 T716 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55417
[junit4:junit4] 2> 227647 T716 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 227648 T716 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 227648 T716 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1370796271809
[junit4:junit4] 2> 227649 T716 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1370796271809/solr.xml
[junit4:junit4] 2> 227649 T716 oasc.CoreContainer.<init> New CoreContainer -1421789856
[junit4:junit4] 2> 227650 T716 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1370796271809/'
[junit4:junit4] 2> 227651 T716 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1370796271809/'
[junit4:junit4] 2> 227689 T716 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 227690 T716 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 227691 T716 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 227691 T716 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 227692 T716 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 227692 T716 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 227693 T716 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 227693 T716 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 227694 T716 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 227695 T716 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 227699 T716 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 227700 T716 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57311/solr
[junit4:junit4] 2> 227701 T716 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 227702 T716 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 227703 T788 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b973dc08 name:ZooKeeperConnection Watcher:127.0.0.1:57311 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 227703 T716 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 227705 T716 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 227711 T716 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 227712 T790 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6ee5de19 name:ZooKeeperConnection Watcher:127.0.0.1:57311/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 227712 T716 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 227715 T716 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 228717 T716 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55417_
[junit4:junit4] 2> 228719 T716 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55417_
[junit4:junit4] 2> 228721 T758 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> 228722 T790 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 228722 T738 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 228722 T745 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 228722 T738 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> 228722 T745 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> 228723 T758 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 228722 T774 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 228724 T774 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> 228728 T791 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1370796271809/collection1
[junit4:junit4] 2> 228728 T791 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 228729 T791 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 228729 T791 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 228730 T791 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1370796271809/collection1/'
[junit4:junit4] 2> 228731 T791 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1370796271809/collection1/lib/README' to classloader
[junit4:junit4] 2> 228731 T791 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1370796271809/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 228755 T791 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 228785 T791 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 228786 T791 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 228790 T791 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 229039 T739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 229039 T739 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:45333",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "node_name":"127.0.0.1:45333_",
[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> 229044 T774 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> 229045 T745 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> 229045 T738 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> 229044 T758 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> 229045 T790 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> 229093 T791 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 229098 T791 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 229100 T791 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 229110 T791 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 229113 T791 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 229117 T791 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 229118 T791 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 229119 T791 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 229119 T791 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 229120 T791 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 229120 T791 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 229121 T791 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 229121 T791 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1370796271809/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty3/
[junit4:junit4] 2> 229121 T791 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2621281d
[junit4:junit4] 2> 229122 T791 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 229123 T791 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty3
[junit4:junit4] 2> 229123 T791 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty3/index/
[junit4:junit4] 2> 229123 T791 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 229124 T791 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty3/index
[junit4:junit4] 2> 229125 T791 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5d110d2e lockFactory=org.apache.lucene.store.NativeFSLockFactory@6803ff2b),segFN=segments_1,generation=1}
[junit4:junit4] 2> 229126 T791 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 229127 T791 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 229127 T791 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 229128 T791 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 229129 T791 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 229129 T791 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 229129 T791 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 229130 T791 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 229130 T791 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 229131 T791 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 229132 T791 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 229134 T791 oass.SolrIndexSearcher.<init> Opening Searcher@e36e160e main
[junit4:junit4] 2> 229134 T791 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty3/tlog
[junit4:junit4] 2> 229135 T791 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 229136 T791 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 229148 T792 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e36e160e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 229149 T791 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 229150 T791 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 230550 T739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 230552 T739 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:55417",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "node_name":"127.0.0.1:55417_",
[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> 230552 T739 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 230553 T739 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 230559 T790 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> 230559 T745 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> 230559 T758 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> 230559 T738 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> 230559 T774 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> 231151 T791 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 231151 T791 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55417 collection:collection1 shard:shard1
[junit4:junit4] 2> 231154 T791 oasc.ZkController.register We are http://127.0.0.1:55417/collection1/ and leader is http://127.0.0.1:51655/collection1/
[junit4:junit4] 2> 231155 T791 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55417
[junit4:junit4] 2> 231155 T791 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 231155 T791 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C174 name=collection1 org.apache.solr.core.SolrCore@c1b4b50 url=http://127.0.0.1:55417/collection1 node=127.0.0.1:55417_ C174_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:55417, state=down, node_name=127.0.0.1:55417_, collection=collection1, core=collection1}
[junit4:junit4] 2> 231156 T793 C174 P55417 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 231156 T791 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 231156 T793 C174 P55417 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 231157 T793 C174 P55417 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 231157 T793 C174 P55417 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 231157 T716 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 231158 T716 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 231159 T716 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 231160 T793 C174 P55417 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 231166 T751 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 231247 T716 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 231249 T716 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58111
[junit4:junit4] 2> 231250 T716 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 231251 T716 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 231251 T716 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1370796275397
[junit4:junit4] 2> 231252 T716 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1370796275397/solr.xml
[junit4:junit4] 2> 231253 T716 oasc.CoreContainer.<init> New CoreContainer 984984796
[junit4:junit4] 2> 231253 T716 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1370796275397/'
[junit4:junit4] 2> 231254 T716 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1370796275397/'
[junit4:junit4] 2> 231294 T716 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 231295 T716 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 231296 T716 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 231297 T716 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 231297 T716 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 231298 T716 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 231299 T716 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 231299 T716 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 231300 T716 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 231301 T716 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 231306 T716 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 231307 T716 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57311/solr
[junit4:junit4] 2> 231307 T716 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 231309 T716 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 231311 T805 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a89b576 name:ZooKeeperConnection Watcher:127.0.0.1:57311 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 231311 T716 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 231313 T716 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 231319 T716 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 231323 T807 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a8aca1fd name:ZooKeeperConnection Watcher:127.0.0.1:57311/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 231323 T716 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 231328 T716 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 232065 T739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 232066 T739 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:55417",
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "node_name":"127.0.0.1:55417_",
[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> 232070 T807 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> 232070 T745 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> 232071 T774 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> 232070 T790 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> 232072 T758 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> 232073 T738 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> 232167 T751 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 232168 T751 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={state=recovering&onlyIfLeader=true&checkLive=true&action=PREPRECOVERY&version=2&coreNodeName=4&wt=javabin&nodeName=127.0.0.1:55417_&core=collection1} status=0 QTime=1002
[junit4:junit4] 2> 232332 T716 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58111_
[junit4:junit4] 2> 232334 T716 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58111_
[junit4:junit4] 2> 232337 T758 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> 232337 T738 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 232337 T745 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 232337 T807 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 232337 T774 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 232337 T790 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 232337 T738 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> 232338 T745 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> 232339 T790 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> 232338 T774 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> 232338 T807 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> 232341 T758 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 232345 T808 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1370796275397/collection1
[junit4:junit4] 2> 232345 T808 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 232346 T808 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 232347 T808 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 232348 T808 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1370796275397/collection1/'
[junit4:junit4] 2> 232349 T808 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1370796275397/collection1/lib/README' to classloader
[junit4:junit4] 2> 232350 T808 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1370796275397/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 232392 T808 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 232443 T808 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 232448 T808 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 232453 T808 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 232781 T808 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 232786 T808 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 232788 T808 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 232804 T808 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 232811 T808 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 232817 T808 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 232818 T808 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 232819 T808 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 232821 T808 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 232823 T808 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 232823 T808 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 232823 T808 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 232824 T808 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1370796275397/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty4/
[junit4:junit4] 2> 232824 T808 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2621281d
[junit4:junit4] 2> 232825 T808 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 232826 T808 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty4
[junit4:junit4] 2> 232826 T808 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty4/index/
[junit4:junit4] 2> 232826 T808 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 232827 T808 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty4/index
[junit4:junit4] 2> 232828 T808 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@67ff238 lockFactory=org.apache.lucene.store.NativeFSLockFactory@962d1a3b),segFN=segments_1,generation=1}
[junit4:junit4] 2> 232829 T808 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 232830 T808 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 232831 T808 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 232831 T808 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 232832 T808 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 232833 T808 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 232833 T808 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 232834 T808 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 232835 T808 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 232835 T808 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 232837 T808 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 232840 T808 oass.SolrIndexSearcher.<init> Opening Searcher@60eeec67 main
[junit4:junit4] 2> 232840 T808 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty4/tlog
[junit4:junit4] 2> 232842 T808 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 232842 T808 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 232846 T809 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@60eeec67 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 232848 T808 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 232848 T808 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 233578 T739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 233579 T739 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:58111",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "node_name":"127.0.0.1:58111_",
[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> 233579 T739 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 233580 T739 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 233588 T758 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> 233588 T790 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> 233589 T807 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> 233589 T738 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> 233589 T774 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> 233588 T745 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> 233860 T808 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 233861 T808 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58111 collection:collection1 shard:shard2
[junit4:junit4] 2> 233864 T808 oasc.ZkController.register We are http://127.0.0.1:58111/collection1/ and leader is http://127.0.0.1:45333/collection1/
[junit4:junit4] 2> 233864 T808 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58111
[junit4:junit4] 2> 233864 T808 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 233865 T808 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C175 name=collection1 org.apache.solr.core.SolrCore@251ae210 url=http://127.0.0.1:58111/collection1 node=127.0.0.1:58111_ C175_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:58111, state=down, node_name=127.0.0.1:58111_, collection=collection1, core=collection1}
[junit4:junit4] 2> 233865 T810 C175 P58111 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 233866 T810 C175 P58111 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 233866 T808 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 233866 T810 C175 P58111 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 233866 T810 C175 P58111 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 233867 T716 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 233868 T716 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 233868 T716 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 233869 T810 C175 P58111 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 233874 T716 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 233875 T716 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 233876 T769 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 233883 T752 oasc.CoreContainer.create Creating SolrCore 'onenodecollectioncore' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370796262774/onenodecollectioncore
[junit4:junit4] 2> 233884 T752 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4] 2> 233885 T752 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4] 2> 233886 T752 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 233887 T752 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 233888 T752 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4] 2> 233890 T752 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4] 2> 233892 T752 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370796262774/onenodecollectioncore/'
[junit4:junit4] 2> 233930 T752 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 233964 T752 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 233965 T752 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 233969 T752 oass.IndexSchema.readSchema [onenodecollectioncore] Schema name=test
[junit4:junit4] 2> ASYNC NEW_CORE C176 name=collection1 org.apache.solr.core.SolrCore@c1b4b50 url=http://127.0.0.1:55417/collection1 node=127.0.0.1:55417_ C176_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:55417, state=recovering, node_name=127.0.0.1:55417_, collection=collection1, shard=shard1, core=collection1}
[junit4:junit4] 2> 234169 T793 C176 P55417 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:51655/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 234169 T793 C176 P55417 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:55417 START replicas=[http://127.0.0.1:51655/collection1/] nUpdates=100
[junit4:junit4] 2> 234170 T793 C176 P55417 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 234170 T793 C176 P55417 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 234171 T793 C176 P55417 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 234171 T793 C176 P55417 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 234171 T793 C176 P55417 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 234172 T793 C176 P55417 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:51655/collection1/. core=collection1
[junit4:junit4] 2> 234173 T793 C176 P55417 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C177 name=collection1 org.apache.solr.core.SolrCore@f3418549 url=http://127.0.0.1:51655/collection1 node=127.0.0.1:51655_ C177_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:51655, state=active, node_name=127.0.0.1:51655_, collection=collection1, shard=shard1, core=collection1, leader=true}
[junit4:junit4] 2> 234183 T751 C177 P51655 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&qt=/get&distrib=false&version=2&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 234187 T751 C177 P51655 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 234189 T751 C177 P51655 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@48d97b5b lockFactory=org.apache.lucene.store.NativeFSLockFactory@aee28c5f),segFN=segments_1,generation=1}
[junit4:junit4] 2> 234190 T751 C177 P51655 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 234191 T751 C177 P51655 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@48d97b5b lockFactory=org.apache.lucene.store.NativeFSLockFactory@aee28c5f),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@48d97b5b lockFactory=org.apache.lucene.store.NativeFSLockFactory@aee28c5f),segFN=segments_2,generation=2}
[junit4:junit4] 2> 234192 T751 C177 P51655 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 234193 T751 C177 P51655 oass.SolrIndexSearcher.<init> Opening Searcher@2e7bfcec realtime
[junit4:junit4] 2> 234194 T751 C177 P51655 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 234195 T751 C177 P51655 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 8
[junit4:junit4] 2> 234197 T793 C176 P55417 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 234197 T793 C176 P55417 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 234201 T751 C177 P51655 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 234202 T751 C177 P51655 oasc.SolrCore.execute [collection1] webapp= path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=2
[junit4:junit4] 2> 234203 T793 C176 P55417 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 234203 T793 C176 P55417 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 234203 T793 C176 P55417 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 234206 T754 C177 P51655 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> 234208 T793 C176 P55417 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 234209 T793 C176 P55417 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty3/index.20130609184438441
[junit4:junit4] 2> 234209 T793 C176 P55417 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@16baf82e lockFactory=org.apache.lucene.store.NativeFSLockFactory@1bd5db5b) fullCopy=false
[junit4:junit4] 2> 234212 T753 C177 P51655 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> 234214 T793 C176 P55417 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 234216 T793 C176 P55417 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 234217 T793 C176 P55417 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 234218 T793 C176 P55417 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5d110d2e lockFactory=org.apache.lucene.store.NativeFSLockFactory@6803ff2b),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5d110d2e lockFactory=org.apache.lucene.store.NativeFSLockFactory@6803ff2b),segFN=segments_2,generation=2}
[junit4:junit4] 2> 234219 T793 C176 P55417 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 234219 T793 C176 P55417 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 234220 T793 C176 P55417 oass.SolrIndexSearcher.<init> Opening Searcher@c5c34c18 main
[junit4:junit4] 2> 234221 T792 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c5c34c18 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 234222 T793 C176 P55417 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty3/index.20130609184438441 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty3/index.20130609184438441;done=true>>]
[junit4:junit4] 2> 234223 T793 C176 P55417 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty3/index.20130609184438441
[junit4:junit4] 2> 234223 T793 C176 P55417 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty3/index.20130609184438441
[junit4:junit4] 2> 234223 T793 C176 P55417 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 234224 T793 C176 P55417 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 234224 T793 C176 P55417 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 234224 T793 C176 P55417 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 234226 T793 C176 P55417 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 234307 T752 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 234311 T752 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 234314 T752 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 234325 T752 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 234330 T752 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 234335 T752 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 234337 T752 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 234337 T752 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 234338 T752 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 234339 T752 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 234340 T752 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 234341 T752 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 234341 T752 oasc.SolrCore.<init> [onenodecollectioncore] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370796262774/onenodecollectioncore/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1370796259321/onenodecollection/
[junit4:junit4] 2> 234342 T752 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2621281d
[junit4:junit4] 2> 234344 T752 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 234346 T752 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1370796259321/onenodecollection
[junit4:junit4] 2> 234347 T752 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1370796259321/onenodecollection/index/
[junit4:junit4] 2> 234347 T752 oasc.SolrCore.initIndex WARN [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1370796259321/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 234348 T752 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1370796259321/onenodecollection/index
[junit4:junit4] 2> 234351 T752 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@bde117ec lockFactory=org.apache.lucene.store.NativeFSLockFactory@6b7ed41a),segFN=segments_1,generation=1}
[junit4:junit4] 2> 234352 T752 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 234354 T752 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 234355 T752 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 234356 T752 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 234357 T752 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 234358 T752 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 234359 T752 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 234360 T752 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 234361 T752 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 234361 T752 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 234363 T752 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 234367 T752 oass.SolrIndexSearcher.<init> Opening Searcher@d984dd78 main
[junit4:junit4] 2> 234368 T752 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1370796259321/onenodecollection/tlog
[junit4:junit4] 2> 234369 T752 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 234369 T752 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 234372 T814 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@d984dd78 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 234373 T752 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> 235094 T739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 235095 T739 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:58111",
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "node_name":"127.0.0.1:58111_",
[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> 235098 T739 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:55417",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "node_name":"127.0.0.1:55417_",
[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> 235101 T739 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:51655",
[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:51655_",
[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> 235101 T739 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4] 2> 235101 T739 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 235104 T758 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> 235105 T807 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> 235105 T790 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> 235105 T738 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> 235105 T745 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> 235105 T774 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> 235375 T752 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4] 2> 235375 T752 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:51655 collection:onenodecollection shard:shard1
[junit4:junit4] 2> 235376 T752 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4] 2> 235381 T752 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 235383 T752 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 235383 T752 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 235384 T752 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51655/onenodecollectioncore/
[junit4:junit4] 2> 235384 T752 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 235385 T752 oasc.SyncStrategy.syncToMe http://127.0.0.1:51655/onenodecollectioncore/ has no replicas
[junit4:junit4] 2> 235385 T752 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51655/onenodecollectioncore/
[junit4:junit4] 2> 235385 T752 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4] 2> 235877 T769 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 235878 T769 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={state=recovering&onlyIfLeader=true&checkLive=true&action=PREPRECOVERY&version=2&coreNodeName=5&wt=javabin&nodeName=127.0.0.1:58111_&core=collection1} status=0 QTime=2002
[junit4:junit4] 2> 236610 T739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 236615 T774 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> 236615 T807 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> 236615 T790 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> 236615 T745 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> 236615 T738 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> 236615 T758 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> 236643 T752 oasc.ZkController.register We are http://127.0.0.1:51655/onenodecollectioncore/ and leader is http://127.0.0.1:51655/onenodecollectioncore/
[junit4:junit4] 2> 236644 T752 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:51655
[junit4:junit4] 2> 236644 T752 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 236645 T752 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4] 2> 236646 T752 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 236647 T752 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1370796259321/onenodecollection&action=CREATE&version=2&numShards=1&name=onenodecollectioncore&wt=javabin&roles=none&collection=onenodecollection} status=0 QTime=2764
[junit4:junit4] 2> 236648 T716 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4] 2> 236649 T716 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 237651 T716 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C178 name=collection1 org.apache.solr.core.SolrCore@251ae210 url=http://127.0.0.1:58111/collection1 node=127.0.0.1:58111_ C178_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:58111, state=recovering, node_name=127.0.0.1:58111_, collection=collection1, shard=shard2, core=collection1}
[junit4:junit4] 2> 237879 T810 C178 P58111 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:45333/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 237880 T810 C178 P58111 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:58111 START replicas=[http://127.0.0.1:45333/collection1/] nUpdates=100
[junit4:junit4] 2> 237880 T810 C178 P58111 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 237880 T810 C178 P58111 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 237881 T810 C178 P58111 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 237881 T810 C178 P58111 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 237881 T810 C178 P58111 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 237881 T810 C178 P58111 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:45333/collection1/. core=collection1
[junit4:junit4] 2> 237882 T810 C178 P58111 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C179 name=collection1 org.apache.solr.core.SolrCore@e4bbae5d url=http://127.0.0.1:45333/collection1 node=127.0.0.1:45333_ C179_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:45333, state=active, node_name=127.0.0.1:45333_, collection=collection1, shard=shard2, core=collection1, leader=true}
[junit4:junit4] 2> 237886 T767 C179 P45333 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> 237888 T768 C179 P45333 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 237890 T768 C179 P45333 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@74618f80 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3a5a2223),segFN=segments_1,generation=1}
[junit4:junit4] 2> 237890 T768 C179 P45333 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 237891 T768 C179 P45333 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@74618f80 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3a5a2223),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@74618f80 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3a5a2223),segFN=segments_2,generation=2}
[junit4:junit4] 2> 237892 T768 C179 P45333 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 237892 T768 C179 P45333 oass.SolrIndexSearcher.<init> Opening Searcher@772ce4f2 realtime
[junit4:junit4] 2> 237893 T768 C179 P45333 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 237893 T768 C179 P45333 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> 237894 T810 C178 P58111 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 237895 T810 C178 P58111 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 237896 T767 C179 P45333 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 237897 T767 C179 P45333 oasc.SolrCore.execute [collection1] webapp= path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 237897 T810 C178 P58111 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 237898 T810 C178 P58111 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 237898 T810 C178 P58111 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 237900 T768 C179 P45333 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> 237901 T810 C178 P58111 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 237902 T810 C178 P58111 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty4/index.20130609184442134
[junit4:junit4] 2> 237902 T810 C178 P58111 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@92f8fa26 lockFactory=org.apache.lucene.store.NativeFSLockFactory@aa537780) fullCopy=false
[junit4:junit4] 2> 237904 T769 C179 P45333 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> 237907 T810 C178 P58111 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 237909 T810 C178 P58111 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 237910 T810 C178 P58111 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 237911 T810 C178 P58111 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@67ff238 lockFactory=org.apache.lucene.store.NativeFSLockFactory@962d1a3b),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@67ff238 lockFactory=org.apache.lucene.store.NativeFSLockFactory@962d1a3b),segFN=segments_2,generation=2}
[junit4:junit4] 2> 237911 T810 C178 P58111 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 237912 T810 C178 P58111 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 237912 T810 C178 P58111 oass.SolrIndexSearcher.<init> Opening Searcher@b79234cf main
[junit4:junit4] 2> 237913 T809 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b79234cf main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 237914 T810 C178 P58111 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty4/index.20130609184442134 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty4/index.20130609184442134;done=true>>]
[junit4:junit4] 2> 237914 T810 C178 P58111 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty4/index.20130609184442134
[junit4:junit4] 2> 237915 T810 C178 P58111 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty4/index.20130609184442134
[junit4:junit4] 2> 237915 T810 C178 P58111 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 237915 T810 C178 P58111 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 237915 T810 C178 P58111 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 237916 T810 C178 P58111 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 237917 T810 C178 P58111 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 238121 T739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 238122 T739 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:51655",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:51655__onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:51655_",
[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> 238124 T739 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:58111",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "node_name":"127.0.0.1:58111_",
[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> 238128 T790 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> 238128 T745 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> 238128 T758 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> 238129 T738 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> 238128 T774 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> 238128 T807 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> 238653 T716 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 238654 T716 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4] 2> 238655 T716 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 238670 T716 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 238671 T818 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f0a493ad name:ZooKeeperConnection Watcher:127.0.0.1:57311 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 238671 T716 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 238706 T716 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 35447
[junit4:junit4] 2> 238707 T716 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=292785768
[junit4:junit4] 2> 239634 T739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 239635 T739 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:35447",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "node_name":"127.0.0.1:35447_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 239640 T790 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> 239640 T807 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> 239640 T774 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> 239640 T758 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> 239640 T738 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> 240708 T716 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 240710 T716 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 240712 T716 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@15657fb5
[junit4:junit4] 2> 240718 T716 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> 240719 T716 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 240720 T716 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 240721 T716 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 240722 T716 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 240724 T716 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 240725 T716 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/control/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/control/data/index;done=false>>]
[junit4:junit4] 2> 240725 T716 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/control/data/index
[junit4:junit4] 2> 240726 T716 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/control/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/control/data;done=false>>]
[junit4:junit4] 2> 240727 T716 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/control/data
[junit4:junit4] 2> 240728 T739 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89836503651057667-127.0.0.1:35447_-n_0000000000) am no longer a leader.
[junit4:junit4] 2> 240729 T758 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> 240729 T790 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 240729 T774 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 240730 T790 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> 240730 T774 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> 240729 T807 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 240731 T758 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 240731 T807 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> 240732 T758 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 240734 T758 oasc.Overseer.start Overseer (id=89836503651057670-127.0.0.1:51655_-n_0000000001) starting
[junit4:junit4] 2> 240737 T820 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 240737 T819 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 240738 T819 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 240739 T819 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:35447",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "node_name":"127.0.0.1:35447_",
[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> 240742 T758 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> 240742 T807 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> 240742 T790 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> 240742 T774 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> 240750 T716 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 240803 T716 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 51655
[junit4:junit4] 2> 240803 T716 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1498582499
[junit4:junit4] 2> 242029 T738 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 242030 T738 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> 242031 T738 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 242246 T819 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 242248 T819 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:51655",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:51655__onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:51655_",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"onenodecollectioncore"}
[junit4:junit4] 2> 242252 T819 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:51655",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "node_name":"127.0.0.1:51655_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 242258 T758 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> 242258 T790 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> 242258 T807 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> 242258 T774 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> 243806 T716 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 243806 T716 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 243808 T716 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> 243809 T716 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@f3418549
[junit4:junit4] 2> 243812 T716 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> 243812 T716 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 243813 T716 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 243813 T716 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 243826 T716 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 243827 T716 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 243827 T716 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty1 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty1;done=false>>]
[junit4:junit4] 2> 243828 T716 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty1
[junit4:junit4] 2> 243829 T716 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty1/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty1/index;done=false>>]
[junit4:junit4] 2> 243829 T716 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty1/index
[junit4:junit4] 2> 243830 T716 oasc.SolrCore.close [onenodecollectioncore] CLOSING SolrCore org.apache.solr.core.SolrCore@e404919e
[junit4:junit4] 2> 243834 T716 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> 243835 T716 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 243836 T716 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 243836 T716 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 243837 T716 oasc.SolrCore.closeSearcher [onenodecollectioncore] Closing main searcher on request.
[junit4:junit4] 2> 243838 T716 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 243838 T716 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1370796259321/onenodecollection [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1370796259321/onenodecollection;done=false>>]
[junit4:junit4] 2> 243839 T716 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1370796259321/onenodecollection
[junit4:junit4] 2> 243839 T716 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1370796259321/onenodecollection/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1370796259321/onenodecollection/index;done=false>>]
[junit4:junit4] 2> 243840 T716 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1370796259321/onenodecollection/index
[junit4:junit4] 2> 243841 T819 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89836503651057670-127.0.0.1:51655_-n_0000000001) am no longer a leader.
[junit4:junit4] 2> 243842 T758 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> 243842 T758 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 243842 T758 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 243843 T774 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 243843 T790 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 243843 T807 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 243843 T774 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> 243844 T807 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> 243845 T790 oasc.ShardLeaderElectionContext.shouldIBeLeader Checking if I should try and be the leader.
[junit4:junit4] 2> 243845 T790 oasc.ShardLeaderElectionContext.shouldIBeLeader My last published State was Active, it's okay to be the leader.
[junit4:junit4] 2> 243846 T790 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 243846 T774 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 243846 T790 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55417/collection1/
[junit4:junit4] 2> 243847 T790 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:55417 START replicas=[http://127.0.0.1:51655/collection1/] nUpdates=100
[junit4:junit4] 2> 243847 T790 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:55417 DONE. We have no versions. sync failed.
[junit4:junit4] 2> 243847 T790 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 243848 T774 oasc.Overseer.start Overseer (id=89836503651057672-127.0.0.1:45333_-n_0000000002) starting
[junit4:junit4] 2> 243848 T790 oasc.ShardLeaderElectionContext.runLeaderProcess We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4:junit4] 2> 243848 T790 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55417/collection1/
[junit4:junit4] 2> 243849 T790 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 243851 T823 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 243851 T822 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 243852 T790 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 243852 T790 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> 243853 T822 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 243854 T822 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:51655",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "node_name":"127.0.0.1:51655_",
[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> 243856 T822 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:51655",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:51655__onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:51655_",
[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> 243863 T790 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> 243863 T774 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> 243863 T716 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 243866 T807 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> 243916 T716 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 45333
[junit4:junit4] 2> 243917 T716 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=-4144296
[junit4:junit4] 2> 244920 T716 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 244920 T716 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 244922 T716 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@e4bbae5d
[junit4:junit4] 2> 244925 T716 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> 244925 T716 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 244926 T716 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 244926 T716 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 244927 T716 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 244928 T716 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 244928 T716 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty2 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty2;done=false>>]
[junit4:junit4] 2> 244929 T716 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty2
[junit4:junit4] 2> 244929 T716 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty2/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty2/index;done=false>>]
[junit4:junit4] 2> 244930 T716 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty2/index
[junit4:junit4] 2> 244931 T822 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89836503651057672-127.0.0.1:45333_-n_0000000002) am no longer a leader.
[junit4:junit4] 2> 244932 T807 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 244932 T790 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 244934 T807 oasc.ShardLeaderElectionContext.shouldIBeLeader Checking if I should try and be the leader.
[junit4:junit4] 2> 244934 T807 oasc.ShardLeaderElectionContext.shouldIBeLeader My last published State was Active, it's okay to be the leader.
[junit4:junit4] 2> 244934 T807 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 244934 T790 oasc.Overseer.start Overseer (id=89836503651057674-127.0.0.1:55417_-n_0000000003) starting
[junit4:junit4] 2> 244935 T807 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58111/collection1/
[junit4:junit4] 2> 244935 T807 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:58111 START replicas=[http://127.0.0.1:45333/collection1/] nUpdates=100
[junit4:junit4] 2> 244936 T807 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:58111 DONE. We have no versions. sync failed.
[junit4:junit4] 2> 244936 T807 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 244936 T807 oasc.ShardLeaderElectionContext.runLeaderProcess We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4:junit4] 2> 244936 T807 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58111/collection1/
[junit4:junit4] 2> 244937 T807 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 244938 T826 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 244939 T790 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 244939 T790 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> 244939 T825 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 244940 T807 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 244941 T807 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> 244941 T825 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 244942 T825 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:45333",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "node_name":"127.0.0.1:45333_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 244942 T716 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 244943 T825 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:45333",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "node_name":"127.0.0.1:45333_",
[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> 244949 T807 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> 244949 T790 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> 244994 T716 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 55417
[junit4:junit4] 2> 244995 T716 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=-1421789856
[junit4:junit4] 2> 245996 T716 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 245997 T716 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 245998 T716 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@c1b4b50
[junit4:junit4] 2> 246001 T716 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> 246002 T716 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 246002 T716 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 246003 T716 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 246004 T716 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 246004 T716 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 246005 T716 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty3/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty3/index;done=false>>]
[junit4:junit4] 2> 246005 T716 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty3/index
[junit4:junit4] 2> 246006 T716 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty3 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty3;done=false>>]
[junit4:junit4] 2> 246006 T716 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty3
[junit4:junit4] 2> 246007 T825 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89836503651057674-127.0.0.1:55417_-n_0000000003) am no longer a leader.
[junit4:junit4] 2> 246008 T807 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4:junit4] 2> 246008 T807 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> 246010 T807 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 246012 T807 oasc.Overseer.start Overseer (id=89836503651057676-127.0.0.1:58111_-n_0000000004) starting
[junit4:junit4] 2> 246016 T828 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 246017 T827 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 246018 T827 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 246019 T827 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55417",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "node_name":"127.0.0.1:55417_",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 246022 T827 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:55417",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "node_name":"127.0.0.1:55417_",
[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> 246025 T807 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> 246028 T716 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 246079 T716 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 58111
[junit4:junit4] 2> 246080 T716 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=984984796
[junit4:junit4] 2> 246232 T774 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 246232 T774 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> 246232 T774 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 247081 T716 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 247082 T716 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 247083 T716 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@251ae210
[junit4:junit4] 2> 247088 T716 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> 247089 T716 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 247089 T716 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 247090 T716 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 247091 T716 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 247091 T716 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 247092 T716 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty4/index;done=false>>]
[junit4:junit4] 2> 247092 T716 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty4/index
[junit4:junit4] 2> 247093 T716 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty4 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty4;done=false>>]
[junit4:junit4] 2> 247093 T716 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370796259320/jetty4
[junit4:junit4] 2> 247094 T827 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89836503651057676-127.0.0.1:58111_-n_0000000004) am no longer a leader.
[junit4:junit4] 2> 247115 T716 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 247171 T716 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 247172 T716 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:57311 57311
[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":"89836503651057667-127.0.0.1:35447_-n_0000000000"}
[junit4:junit4] 1> /solr/overseer_elect/election (5)
[junit4:junit4] 1> /solr/overseer_elect/election/89836503651057670-127.0.0.1:51655_-n_0000000001 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89836503651057667-127.0.0.1:35447_-n_0000000000 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89836503651057672-127.0.0.1:45333_-n_0000000002 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89836503651057676-127.0.0.1:58111_-n_0000000004 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89836503651057674-127.0.0.1:55417_-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/89836503651057667-1-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:35447",
[junit4:junit4] 1> "node_name":"127.0.0.1:35447_",
[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/89836503651057670-2-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/89836503651057674-4-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/89836503651057676-5-n_0000000001 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2/election/89836503651057672-3-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:51655",
[junit4:junit4] 1> "node_name":"127.0.0.1:51655_",
[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:45333",
[junit4:junit4] 1> "node_name":"127.0.0.1:45333_",
[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/89836503651057670-127.0.0.1:51655__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:51655",
[junit4:junit4] 1> "node_name":"127.0.0.1:51655_",
[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:55417_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:45333_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:51655_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:58111_ (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:35447_ (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":{"1":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:35447",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:35447_",
[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:51655__onenodecollectioncore":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:51655",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:51655_",
[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> "2":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:51655",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:51655_",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "leader":"true"},
[junit4:junit4] 1> "4":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:55417",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:55417_",
[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> "3":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:45333",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:45333_",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "shard":"shard2",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "leader":"true"},
[junit4:junit4] 1> "5":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:58111",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:58111_",
[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=1A716F651BA0B9AB -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=de_LU -Dtests.timezone=Europe/Malta -Dtests.file.encoding=UTF-8
[junit4:junit4] ERROR 32.1s J1 | BasicDistributedZk2Test.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:45333/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([1A716F651BA0B9AB:9B97E17D6CFFD997]: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> 247191 T716 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 32116 T715 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 4 leaked thread(s).
[junit4:junit4] 2> 247307 T790 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 247308 T790 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> 247308 T790 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 248395 T807 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 248395 T807 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> 248395 T807 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=DefaultSimilarity, locale=de_LU, timezone=Europe/Malta
[junit4:junit4] 2> NOTE: Linux 3.2.0-45-generic x86/IBM Corporation 1.7.0 (32-bit)/cpus=8,threads=3,free=105590440,total=173539328
[junit4:junit4] 2> NOTE: All tests run in this JVM: [UpdateParamsTest, TestRTGBase, StandardRequestHandlerTest, TestReload, ZkNodePropsTest, DateMathParserTest, TestZkChroot, NoCacheHeaderTest, RequestHandlersTest, TestLuceneMatchVersion, TestSolrXml, CurrencyFieldXmlFileTest, DOMUtilTest, TestUpdate, FullSolrCloudDistribCmdsTest, ShardRoutingCustomTest, TestOmitPositions, ClusterStateTest, TestPartialUpdateDeduplication, DocumentAnalysisRequestHandlerTest, DirectSolrSpellCheckerTest, CoreContainerCoreInitFailuresTest, HardAutoCommitTest, JSONWriterTest, TestSuggestSpellingConverter, TestWordDelimiterFilterFactory, TestCollationField, TestMultiCoreConfBootstrap, HighlighterConfigTest, DirectUpdateHandlerTest, TestAddFieldRealTimeGet, TestComponentsName, EchoParamsTest, CollectionsAPIDistributedZkTest, TestManagedSchema, DocValuesMultiTest, BasicDistributedZk2Test]
[junit4:junit4] Completed on J1 in 33.40s, 1 test, 1 error <<< FAILURES!
[...truncated 700 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:391: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:384: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:437: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1243: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:887: There were test failures: 297 suites, 1246 tests, 1 error, 14 ignored (8 assumptions)
Total time: 44 minutes 18 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