You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/06/05 08:05:59 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/ibm-j9-jdk7) - Build #
5990 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-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:50373/yuf/v/onenodecollectioncore returned non ok status:404, message:Can not find: /yuf/v/onenodecollectioncore/update
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:50373/yuf/v/onenodecollectioncore returned non ok status:404, message:Can not find: /yuf/v/onenodecollectioncore/update
at __randomizedtesting.SeedInfo.seed([73BF5CAB17741375:F259D2B3602B7349]: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 9581 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4] 2> 659612 T3052 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /yuf/v
[junit4:junit4] 2> 659617 T3052 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1370411730425
[junit4:junit4] 2> 659618 T3052 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 659619 T3053 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 659719 T3052 oasc.ZkTestServer.run start zk server on port:41252
[junit4:junit4] 2> 659722 T3052 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 659733 T3059 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55c1791a name:ZooKeeperConnection Watcher:127.0.0.1:41252 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 659733 T3052 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 659733 T3052 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 659739 T3052 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 659740 T3061 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@be054c26 name:ZooKeeperConnection Watcher:127.0.0.1:41252/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 659741 T3052 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 659741 T3052 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 659743 T3052 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 659745 T3052 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 659747 T3052 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 659748 T3052 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 659749 T3052 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 659751 T3052 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 659752 T3052 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 659755 T3052 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 659755 T3052 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 659757 T3052 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 659758 T3052 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 659760 T3052 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 659760 T3052 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 659762 T3052 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 659763 T3052 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 659764 T3052 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 659765 T3052 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 659767 T3052 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 659768 T3052 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 659769 T3052 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 659770 T3052 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 659837 T3052 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 659843 T3052 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:?????
[junit4:junit4] 2> 659843 T3052 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 659844 T3052 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 659845 T3052 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1370411730579
[junit4:junit4] 2> 659845 T3052 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1370411730579/solr.xml
[junit4:junit4] 2> 659846 T3052 oasc.CoreContainer.<init> New CoreContainer -1500701346
[junit4:junit4] 2> 659846 T3052 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1370411730579/'
[junit4:junit4] 2> 659847 T3052 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1370411730579/'
[junit4:junit4] 2> 659899 T3052 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 659900 T3052 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 659900 T3052 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 659901 T3052 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 659901 T3052 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 659902 T3052 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 659903 T3052 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 659903 T3052 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 659904 T3052 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 659905 T3052 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 659909 T3052 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 659910 T3052 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:41252/solr
[junit4:junit4] 2> 659910 T3052 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 659913 T3052 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 659914 T3072 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c64645a4 name:ZooKeeperConnection Watcher:127.0.0.1:41252 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 659915 T3052 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 659916 T3052 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 659922 T3052 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 659923 T3074 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@73686013 name:ZooKeeperConnection Watcher:127.0.0.1:41252/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 659924 T3052 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 659925 T3052 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 659927 T3052 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 659930 T3052 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 659931 T3052 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51682_yuf%2Fv
[junit4:junit4] 2> 659932 T3052 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51682_yuf%2Fv
[junit4:junit4] 2> 659934 T3052 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 659938 T3052 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 659940 T3052 oasc.Overseer.start Overseer (id=89811303165394947-127.0.0.1:51682_yuf%2Fv-n_0000000000) starting
[junit4:junit4] 2> 659943 T3052 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 659945 T3076 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 659945 T3052 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 659947 T3052 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 659948 T3052 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 659950 T3075 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 659952 T3077 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1370411730579/collection1
[junit4:junit4] 2> 659953 T3077 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 659953 T3077 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 659953 T3077 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 659955 T3077 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1370411730579/collection1/'
[junit4:junit4] 2> 659956 T3077 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1370411730579/collection1/lib/README' to classloader
[junit4:junit4] 2> 659956 T3077 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1370411730579/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 659980 T3077 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 660010 T3077 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 660011 T3077 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 660016 T3077 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 660321 T3077 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 660326 T3077 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 660328 T3077 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 660339 T3077 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 660343 T3077 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 660348 T3077 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 660350 T3077 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 660350 T3077 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 660351 T3077 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 660352 T3077 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 660352 T3077 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 660353 T3077 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 660353 T3077 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1370411730579/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/control/data/
[junit4:junit4] 2> 660354 T3077 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5cc50aa0
[junit4:junit4] 2> 660354 T3077 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 660355 T3077 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/control/data
[junit4:junit4] 2> 660355 T3077 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/control/data/index/
[junit4:junit4] 2> 660356 T3077 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 660357 T3077 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/control/data/index
[junit4:junit4] 2> 660358 T3077 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@94559d1b lockFactory=org.apache.lucene.store.NativeFSLockFactory@3dc22f90),segFN=segments_1,generation=1}
[junit4:junit4] 2> 660359 T3077 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 660361 T3077 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 660361 T3077 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 660362 T3077 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 660363 T3077 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 660363 T3077 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 660364 T3077 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 660364 T3077 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 660365 T3077 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 660366 T3077 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 660367 T3077 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 660369 T3077 oass.SolrIndexSearcher.<init> Opening Searcher@eb86c97c main
[junit4:junit4] 2> 660370 T3077 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/control/data/tlog
[junit4:junit4] 2> 660371 T3077 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 660371 T3077 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 660375 T3078 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@eb86c97c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 660376 T3077 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 660376 T3077 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 661454 T3075 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 661455 T3075 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:51682/yuf/v",
[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:51682_yuf%2Fv",
[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> 661456 T3075 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 661456 T3075 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 661461 T3074 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> 662378 T3077 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 662379 T3077 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51682/yuf/v collection:control_collection shard:shard1
[junit4:junit4] 2> 662380 T3077 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 662384 T3077 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 662386 T3077 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 662386 T3077 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 662386 T3077 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51682/yuf/v/collection1/
[junit4:junit4] 2> 662387 T3077 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 662387 T3077 oasc.SyncStrategy.syncToMe http://127.0.0.1:51682/yuf/v/collection1/ has no replicas
[junit4:junit4] 2> 662388 T3077 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51682/yuf/v/collection1/
[junit4:junit4] 2> 662388 T3077 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 662965 T3075 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 662970 T3074 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> 662993 T3077 oasc.ZkController.register We are http://127.0.0.1:51682/yuf/v/collection1/ and leader is http://127.0.0.1:51682/yuf/v/collection1/
[junit4:junit4] 2> 662993 T3077 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51682/yuf/v
[junit4:junit4] 2> 662994 T3077 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 662994 T3077 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 662994 T3077 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 662997 T3077 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 662998 T3052 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 662998 T3052 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 662999 T3052 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 663004 T3052 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 663007 T3052 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 663008 T3081 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2b369da3 name:ZooKeeperConnection Watcher:127.0.0.1:41252/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 663008 T3052 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 663009 T3052 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 663012 T3052 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 663085 T3052 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 663090 T3052 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:?????
[junit4:junit4] 2> 663091 T3052 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 663091 T3052 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 663092 T3052 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370411733819
[junit4:junit4] 2> 663092 T3052 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370411733819/solr.xml
[junit4:junit4] 2> 663093 T3052 oasc.CoreContainer.<init> New CoreContainer 1098941372
[junit4:junit4] 2> 663093 T3052 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370411733819/'
[junit4:junit4] 2> 663094 T3052 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370411733819/'
[junit4:junit4] 2> 663132 T3052 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 663133 T3052 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 663134 T3052 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 663134 T3052 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 663135 T3052 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 663135 T3052 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 663136 T3052 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 663136 T3052 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 663137 T3052 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 663138 T3052 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 663142 T3052 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 663143 T3052 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:41252/solr
[junit4:junit4] 2> 663144 T3052 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 663146 T3052 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 663147 T3092 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55d6eef8 name:ZooKeeperConnection Watcher:127.0.0.1:41252 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 663148 T3052 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 663149 T3052 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 663155 T3052 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 663156 T3094 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2c2d3b43 name:ZooKeeperConnection Watcher:127.0.0.1:41252/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 663157 T3052 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 663160 T3052 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 664173 T3052 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47550_yuf%2Fv
[junit4:junit4] 2> 664176 T3052 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47550_yuf%2Fv
[junit4:junit4] 2> 664178 T3094 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 664178 T3074 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 664178 T3081 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 664178 T3074 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> 664181 T3095 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370411733819/collection1
[junit4:junit4] 2> 664182 T3095 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 664183 T3095 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 664183 T3095 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 664184 T3095 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370411733819/collection1/'
[junit4:junit4] 2> 664185 T3095 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370411733819/collection1/lib/README' to classloader
[junit4:junit4] 2> 664185 T3095 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370411733819/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 664210 T3095 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 664240 T3095 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 664242 T3095 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 664246 T3095 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 664475 T3075 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 664476 T3075 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:51682/yuf/v",
[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:51682_yuf%2Fv",
[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> 664478 T3094 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> 664478 T3081 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> 664482 T3074 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> 664551 T3095 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 664555 T3095 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 664558 T3095 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 664568 T3095 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 664572 T3095 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 664576 T3095 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 664577 T3095 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 664577 T3095 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 664578 T3095 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 664579 T3095 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 664579 T3095 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 664579 T3095 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 664580 T3095 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370411733819/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty1/
[junit4:junit4] 2> 664580 T3095 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5cc50aa0
[junit4:junit4] 2> 664581 T3095 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 664582 T3095 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty1
[junit4:junit4] 2> 664582 T3095 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty1/index/
[junit4:junit4] 2> 664582 T3095 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 664583 T3095 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty1/index
[junit4:junit4] 2> 664584 T3095 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e132cb2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@acfefa4d),segFN=segments_1,generation=1}
[junit4:junit4] 2> 664585 T3095 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 664587 T3095 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 664587 T3095 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 664588 T3095 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 664588 T3095 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 664589 T3095 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 664589 T3095 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 664589 T3095 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 664590 T3095 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 664590 T3095 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 664592 T3095 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 664594 T3095 oass.SolrIndexSearcher.<init> Opening Searcher@40b4d43b main
[junit4:junit4] 2> 664594 T3095 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty1/tlog
[junit4:junit4] 2> 664595 T3095 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 664595 T3095 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 664599 T3096 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@40b4d43b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 664600 T3095 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 664601 T3095 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 665986 T3075 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 665988 T3075 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:47550/yuf/v",
[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:47550_yuf%2Fv",
[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> 665988 T3075 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 665989 T3075 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 665995 T3074 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> 665995 T3094 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> 665995 T3081 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> 666602 T3095 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 666603 T3095 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:47550/yuf/v collection:collection1 shard:shard1
[junit4:junit4] 2> 666604 T3095 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 666613 T3095 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 666617 T3095 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 666617 T3095 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 666618 T3095 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:47550/yuf/v/collection1/
[junit4:junit4] 2> 666619 T3095 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 666619 T3095 oasc.SyncStrategy.syncToMe http://127.0.0.1:47550/yuf/v/collection1/ has no replicas
[junit4:junit4] 2> 666620 T3095 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:47550/yuf/v/collection1/
[junit4:junit4] 2> 666621 T3095 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 667500 T3075 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 667505 T3074 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> 667505 T3081 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> 667505 T3094 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> 667529 T3095 oasc.ZkController.register We are http://127.0.0.1:47550/yuf/v/collection1/ and leader is http://127.0.0.1:47550/yuf/v/collection1/
[junit4:junit4] 2> 667530 T3095 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:47550/yuf/v
[junit4:junit4] 2> 667530 T3095 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 667531 T3095 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 667531 T3095 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 667534 T3095 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 667535 T3052 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 667536 T3052 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 667537 T3052 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 667611 T3052 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 667617 T3052 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:?????
[junit4:junit4] 2> 667618 T3052 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 667618 T3052 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 667619 T3052 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1370411738351
[junit4:junit4] 2> 667619 T3052 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1370411738351/solr.xml
[junit4:junit4] 2> 667620 T3052 oasc.CoreContainer.<init> New CoreContainer 882914814
[junit4:junit4] 2> 667620 T3052 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1370411738351/'
[junit4:junit4] 2> 667621 T3052 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1370411738351/'
[junit4:junit4] 2> 667659 T3052 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 667660 T3052 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 667660 T3052 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 667661 T3052 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 667662 T3052 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 667662 T3052 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 667663 T3052 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 667663 T3052 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 667664 T3052 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 667665 T3052 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 667670 T3052 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 667670 T3052 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:41252/solr
[junit4:junit4] 2> 667671 T3052 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 667674 T3052 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 667676 T3108 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32fca8b4 name:ZooKeeperConnection Watcher:127.0.0.1:41252 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 667676 T3052 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 667677 T3052 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 667685 T3052 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 667686 T3110 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cf472909 name:ZooKeeperConnection Watcher:127.0.0.1:41252/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 667686 T3052 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 667689 T3052 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 668691 T3052 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50373_yuf%2Fv
[junit4:junit4] 2> 668694 T3052 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50373_yuf%2Fv
[junit4:junit4] 2> 668697 T3081 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> 668698 T3074 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 668698 T3094 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 668698 T3110 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 668698 T3074 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> 668700 T3081 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 668699 T3094 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> 668703 T3111 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1370411738351/collection1
[junit4:junit4] 2> 668703 T3111 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 668704 T3111 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 668704 T3111 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 668705 T3111 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1370411738351/collection1/'
[junit4:junit4] 2> 668706 T3111 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1370411738351/collection1/lib/README' to classloader
[junit4:junit4] 2> 668707 T3111 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1370411738351/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 668742 T3111 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 668772 T3111 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 668773 T3111 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 668777 T3111 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 669009 T3075 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 669009 T3075 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:47550/yuf/v",
[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:47550_yuf%2Fv",
[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> 669012 T3110 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> 669012 T3081 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> 669012 T3074 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> 669012 T3094 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> 669094 T3111 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 669099 T3111 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 669101 T3111 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 669114 T3111 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 669121 T3111 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 669125 T3111 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 669126 T3111 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 669126 T3111 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 669127 T3111 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 669128 T3111 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 669128 T3111 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 669128 T3111 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 669129 T3111 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1370411738351/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty2/
[junit4:junit4] 2> 669129 T3111 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5cc50aa0
[junit4:junit4] 2> 669130 T3111 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 669130 T3111 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty2
[junit4:junit4] 2> 669131 T3111 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty2/index/
[junit4:junit4] 2> 669131 T3111 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 669132 T3111 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty2/index
[junit4:junit4] 2> 669133 T3111 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@42129c81 lockFactory=org.apache.lucene.store.NativeFSLockFactory@fdda1546),segFN=segments_1,generation=1}
[junit4:junit4] 2> 669133 T3111 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 669135 T3111 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 669136 T3111 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 669136 T3111 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 669137 T3111 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 669137 T3111 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 669138 T3111 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 669138 T3111 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 669139 T3111 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 669139 T3111 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 669140 T3111 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 669142 T3111 oass.SolrIndexSearcher.<init> Opening Searcher@587722e1 main
[junit4:junit4] 2> 669143 T3111 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty2/tlog
[junit4:junit4] 2> 669143 T3111 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 669144 T3111 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 669148 T3112 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@587722e1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 669150 T3111 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 669151 T3111 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 670516 T3075 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 670517 T3075 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:50373/yuf/v",
[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:50373_yuf%2Fv",
[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> 670518 T3075 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 670518 T3075 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 670523 T3074 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> 670523 T3081 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> 670523 T3110 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> 670523 T3094 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> 671152 T3111 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 671153 T3111 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50373/yuf/v collection:collection1 shard:shard2
[junit4:junit4] 2> 671154 T3111 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 671159 T3111 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 671160 T3111 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 671161 T3111 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 671161 T3111 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50373/yuf/v/collection1/
[junit4:junit4] 2> 671161 T3111 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 671162 T3111 oasc.SyncStrategy.syncToMe http://127.0.0.1:50373/yuf/v/collection1/ has no replicas
[junit4:junit4] 2> 671162 T3111 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50373/yuf/v/collection1/
[junit4:junit4] 2> 671162 T3111 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 672029 T3075 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 672038 T3081 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> 672038 T3110 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> 672038 T3074 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> 672038 T3094 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> 672068 T3111 oasc.ZkController.register We are http://127.0.0.1:50373/yuf/v/collection1/ and leader is http://127.0.0.1:50373/yuf/v/collection1/
[junit4:junit4] 2> 672069 T3111 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50373/yuf/v
[junit4:junit4] 2> 672069 T3111 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 672070 T3111 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 672071 T3111 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 672073 T3111 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 672074 T3052 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 672076 T3052 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 672077 T3052 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 672178 T3052 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 672183 T3052 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:?????
[junit4:junit4] 2> 672184 T3052 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 672184 T3052 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 672185 T3052 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1370411742894
[junit4:junit4] 2> 672186 T3052 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1370411742894/solr.xml
[junit4:junit4] 2> 672186 T3052 oasc.CoreContainer.<init> New CoreContainer 1568612555
[junit4:junit4] 2> 672187 T3052 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1370411742894/'
[junit4:junit4] 2> 672187 T3052 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1370411742894/'
[junit4:junit4] 2> 672228 T3052 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 672229 T3052 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 672230 T3052 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 672230 T3052 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 672231 T3052 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 672232 T3052 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 672232 T3052 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 672233 T3052 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 672233 T3052 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 672234 T3052 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 672239 T3052 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 672240 T3052 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:41252/solr
[junit4:junit4] 2> 672240 T3052 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 672243 T3052 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 672244 T3124 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ff793c95 name:ZooKeeperConnection Watcher:127.0.0.1:41252 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 672244 T3052 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 672246 T3052 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 672252 T3052 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 672253 T3126 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e7bc388 name:ZooKeeperConnection Watcher:127.0.0.1:41252/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 672253 T3052 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 672256 T3052 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 673259 T3052 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40781_yuf%2Fv
[junit4:junit4] 2> 673261 T3052 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40781_yuf%2Fv
[junit4:junit4] 2> 673263 T3110 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> 673263 T3081 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> 673264 T3126 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 673265 T3094 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 673265 T3074 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 673265 T3094 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> 673265 T3074 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> 673265 T3081 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 673266 T3110 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 673269 T3127 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1370411742894/collection1
[junit4:junit4] 2> 673269 T3127 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 673270 T3127 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 673270 T3127 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 673271 T3127 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1370411742894/collection1/'
[junit4:junit4] 2> 673272 T3127 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1370411742894/collection1/lib/README' to classloader
[junit4:junit4] 2> 673273 T3127 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1370411742894/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 673351 T3127 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 673382 T3127 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 673384 T3127 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 673389 T3127 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 673544 T3075 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 673545 T3075 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:50373/yuf/v",
[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:50373_yuf%2Fv",
[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> 673548 T3081 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> 673548 T3094 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> 673548 T3126 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> 673549 T3110 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> 673548 T3074 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> 673705 T3127 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 673711 T3127 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 673713 T3127 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 673727 T3127 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 673732 T3127 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 673737 T3127 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 673739 T3127 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 673740 T3127 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 673740 T3127 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 673742 T3127 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 673742 T3127 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 673743 T3127 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 673743 T3127 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1370411742894/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty3/
[junit4:junit4] 2> 673744 T3127 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5cc50aa0
[junit4:junit4] 2> 673745 T3127 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 673746 T3127 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty3
[junit4:junit4] 2> 673747 T3127 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty3/index/
[junit4:junit4] 2> 673748 T3127 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 673749 T3127 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty3/index
[junit4:junit4] 2> 673751 T3127 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@39cac026 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4653a9a3),segFN=segments_1,generation=1}
[junit4:junit4] 2> 673752 T3127 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 673755 T3127 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 673756 T3127 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 673757 T3127 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 673758 T3127 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 673759 T3127 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 673760 T3127 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 673761 T3127 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 673762 T3127 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 673762 T3127 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 673764 T3127 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 673766 T3127 oass.SolrIndexSearcher.<init> Opening Searcher@726ee289 main
[junit4:junit4] 2> 673766 T3127 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty3/tlog
[junit4:junit4] 2> 673767 T3127 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 673767 T3127 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 673774 T3128 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@726ee289 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 673776 T3127 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 673777 T3127 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 675053 T3075 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 675054 T3075 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:40781/yuf/v",
[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:40781_yuf%2Fv",
[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> 675055 T3075 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 675056 T3075 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 675060 T3110 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> 675060 T3081 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> 675060 T3094 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> 675061 T3074 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> 675060 T3126 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> 675780 T3127 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 675781 T3127 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:40781/yuf/v collection:collection1 shard:shard1
[junit4:junit4] 2> 675806 T3127 oasc.ZkController.register We are http://127.0.0.1:40781/yuf/v/collection1/ and leader is http://127.0.0.1:47550/yuf/v/collection1/
[junit4:junit4] 2> 675806 T3127 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:40781/yuf/v
[junit4:junit4] 2> 675807 T3127 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 675807 T3127 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C955 name=collection1 org.apache.solr.core.SolrCore@ad115204 url=http://127.0.0.1:40781/yuf/v/collection1 node=127.0.0.1:40781_yuf%2Fv C955_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:40781/yuf/v, state=down, node_name=127.0.0.1:40781_yuf%2Fv, collection=collection1, core=collection1}
[junit4:junit4] 2> 675808 T3129 C955 P40781 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 675809 T3127 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 675809 T3129 C955 P40781 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 675811 T3129 C955 P40781 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 675811 T3129 C955 P40781 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 675811 T3052 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 675813 T3052 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 675814 T3052 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 675823 T3129 C955 P40781 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 675828 T3089 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 675887 T3052 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 675892 T3052 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:?????
[junit4:junit4] 2> 675893 T3052 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 675893 T3052 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 675894 T3052 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1370411746630
[junit4:junit4] 2> 675894 T3052 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1370411746630/solr.xml
[junit4:junit4] 2> 675895 T3052 oasc.CoreContainer.<init> New CoreContainer 1460132615
[junit4:junit4] 2> 675896 T3052 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1370411746630/'
[junit4:junit4] 2> 675896 T3052 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1370411746630/'
[junit4:junit4] 2> 675937 T3052 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 675938 T3052 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 675938 T3052 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 675939 T3052 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 675939 T3052 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 675940 T3052 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 675940 T3052 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 675941 T3052 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 675942 T3052 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 675942 T3052 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 675947 T3052 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 675948 T3052 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:41252/solr
[junit4:junit4] 2> 675948 T3052 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 675951 T3052 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 675952 T3141 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9a488718 name:ZooKeeperConnection Watcher:127.0.0.1:41252 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 675953 T3052 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 675954 T3052 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 675960 T3052 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 675961 T3143 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fa4cd6d5 name:ZooKeeperConnection Watcher:127.0.0.1:41252/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 675962 T3052 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 675966 T3052 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 676564 T3075 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 676565 T3075 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:40781/yuf/v",
[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:40781_yuf%2Fv",
[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> 676663 T3081 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> 676663 T3143 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> 676663 T3126 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> 676663 T3110 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> 676663 T3074 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> 676663 T3094 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> 676829 T3089 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 676829 T3089 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:40781_yuf%252Fv&core=collection1} status=0 QTime=1001
[junit4:junit4] 2> 676968 T3052 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60986_yuf%2Fv
[junit4:junit4] 2> 676970 T3052 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60986_yuf%2Fv
[junit4:junit4] 2> 676972 T3110 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> 676972 T3126 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> 676973 T3143 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> 676973 T3094 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 676973 T3110 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 676973 T3074 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 676974 T3126 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 676973 T3081 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> 676975 T3143 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 676975 T3074 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> 676974 T3094 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> 676978 T3144 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1370411746630/collection1
[junit4:junit4] 2> 676978 T3081 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 676978 T3144 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 676979 T3144 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 676980 T3144 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 676980 T3144 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1370411746630/collection1/'
[junit4:junit4] 2> 676981 T3144 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1370411746630/collection1/lib/README' to classloader
[junit4:junit4] 2> 676981 T3144 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1370411746630/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 677005 T3144 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 677043 T3144 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 677045 T3144 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 677049 T3144 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 677373 T3144 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 677378 T3144 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 677380 T3144 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 677390 T3144 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 677393 T3144 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 677397 T3144 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 677397 T3144 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 677398 T3144 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 677398 T3144 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 677399 T3144 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 677399 T3144 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 677400 T3144 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 677400 T3144 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1370411746630/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty4/
[junit4:junit4] 2> 677400 T3144 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5cc50aa0
[junit4:junit4] 2> 677401 T3144 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 677402 T3144 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty4
[junit4:junit4] 2> 677402 T3144 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty4/index/
[junit4:junit4] 2> 677402 T3144 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 677403 T3144 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty4/index
[junit4:junit4] 2> 677404 T3144 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6fa51399 lockFactory=org.apache.lucene.store.NativeFSLockFactory@ef8ed41b),segFN=segments_1,generation=1}
[junit4:junit4] 2> 677405 T3144 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 677406 T3144 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 677406 T3144 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 677407 T3144 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 677408 T3144 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 677408 T3144 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 677408 T3144 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 677409 T3144 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 677409 T3144 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 677410 T3144 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 677411 T3144 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 677414 T3144 oass.SolrIndexSearcher.<init> Opening Searcher@b53a4016 main
[junit4:junit4] 2> 677414 T3144 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty4/tlog
[junit4:junit4] 2> 677415 T3144 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 677415 T3144 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 677419 T3145 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b53a4016 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 677420 T3144 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 677420 T3144 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 678167 T3075 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 678167 T3075 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:60986/yuf/v",
[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:60986_yuf%2Fv",
[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> 678168 T3075 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 678168 T3075 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 678171 T3074 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> 678171 T3126 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 678171 T3081 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> 678171 T3110 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> 678171 T3094 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> 678171 T3143 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 678421 T3144 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 678422 T3144 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:60986/yuf/v collection:collection1 shard:shard2
[junit4:junit4] 2> 678424 T3144 oasc.ZkController.register We are http://127.0.0.1:60986/yuf/v/collection1/ and leader is http://127.0.0.1:50373/yuf/v/collection1/
[junit4:junit4] 2> 678425 T3144 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60986/yuf/v
[junit4:junit4] 2> 678425 T3144 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 678425 T3144 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C956 name=collection1 org.apache.solr.core.SolrCore@223abfa2 url=http://127.0.0.1:60986/yuf/v/collection1 node=127.0.0.1:60986_yuf%2Fv C956_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:60986/yuf/v, state=down, node_name=127.0.0.1:60986_yuf%2Fv, collection=collection1, core=collection1}
[junit4:junit4] 2> 678426 T3146 C956 P60986 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 678426 T3144 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 678426 T3146 C956 P60986 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 678427 T3146 C956 P60986 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 678427 T3146 C956 P60986 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 678427 T3052 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 678428 T3052 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 678428 T3146 C956 P60986 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 678429 T3052 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 678433 T3052 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 678434 T3104 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 678434 T3052 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 678440 T3089 oasc.CoreContainer.create Creating SolrCore 'onenodecollectioncore' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370411733819/onenodecollectioncore
[junit4:junit4] 2> 678441 T3089 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4] 2> 678442 T3089 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4] 2> 678442 T3089 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 678443 T3089 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 678444 T3089 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4] 2> 678445 T3089 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4] 2> 678447 T3089 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370411733819/onenodecollectioncore/'
[junit4:junit4] 2> 678470 T3089 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 678500 T3089 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 678502 T3089 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 678506 T3089 oass.IndexSchema.readSchema [onenodecollectioncore] Schema name=test
[junit4:junit4] 2> 678830 T3089 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> ASYNC NEW_CORE C957 name=collection1 org.apache.solr.core.SolrCore@ad115204 url=http://127.0.0.1:40781/yuf/v/collection1 node=127.0.0.1:40781_yuf%2Fv C957_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:40781/yuf/v, state=recovering, node_name=127.0.0.1:40781_yuf%2Fv, collection=collection1, shard=shard1, core=collection1}
[junit4:junit4] 2> 678830 T3129 C957 P40781 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:47550/yuf/v/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 678831 T3129 C957 P40781 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:40781/yuf/v START replicas=[http://127.0.0.1:47550/yuf/v/collection1/] nUpdates=100
[junit4:junit4] 2> 678831 T3129 C957 P40781 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 678832 T3129 C957 P40781 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 678832 T3129 C957 P40781 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 678832 T3129 C957 P40781 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 678832 T3129 C957 P40781 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 678833 T3129 C957 P40781 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:47550/yuf/v/collection1/. core=collection1
[junit4:junit4] 2> 678833 T3129 C957 P40781 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C958 name=collection1 org.apache.solr.core.SolrCore@b780d6c4 url=http://127.0.0.1:47550/yuf/v/collection1 node=127.0.0.1:47550_yuf%2Fv C958_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:47550/yuf/v, state=active, node_name=127.0.0.1:47550_yuf%2Fv, collection=collection1, shard=shard1, core=collection1, leader=true}
[junit4:junit4] 2> 678836 T3090 C958 P47550 oasc.SolrCore.execute [collection1] webapp=/yuf/v path=/get params={getVersions=100&qt=/get&distrib=false&version=2&wt=javabin} status=0 QTime=0
[junit4:junit4] 2> 678836 T3089 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 678838 T3088 C958 P47550 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 678839 T3089 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 678839 T3088 C958 P47550 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e132cb2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@acfefa4d),segFN=segments_1,generation=1}
[junit4:junit4] 2> 678841 T3088 C958 P47550 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 678841 T3088 C958 P47550 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e132cb2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@acfefa4d),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e132cb2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@acfefa4d),segFN=segments_2,generation=2}
[junit4:junit4] 2> 678842 T3088 C958 P47550 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 678843 T3088 C958 P47550 oass.SolrIndexSearcher.<init> Opening Searcher@44c8b9ee realtime
[junit4:junit4] 2> 678843 T3088 C958 P47550 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 678844 T3088 C958 P47550 oasup.LogUpdateProcessor.finish [collection1] webapp=/yuf/v path=/update params={softCommit=false&commit_end_point=true&commit=true&version=2&waitSearcher=true&wt=javabin&openSearcher=false} {commit=} 0 6
[junit4:junit4] 2> 678845 T3129 C957 P40781 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 678845 T3129 C957 P40781 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 678846 T3087 C958 P47550 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 678847 T3087 C958 P47550 oasc.SolrCore.execute [collection1] webapp=/yuf/v path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 678848 T3129 C957 P40781 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 678849 T3129 C957 P40781 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 678849 T3129 C957 P40781 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 678850 T3089 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 678851 T3088 C958 P47550 oasc.SolrCore.execute [collection1] webapp=/yuf/v path=/replication params={qt=/replication&version=2&generation=2&command=filelist&wt=javabin} status=0 QTime=0
[junit4:junit4] 2> 678852 T3129 C957 P40781 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 678852 T3129 C957 P40781 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty3/index.20130605165549659
[junit4:junit4] 2> 678852 T3129 C957 P40781 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@e9838002 lockFactory=org.apache.lucene.store.NativeFSLockFactory@149d815e) fullCopy=false
[junit4:junit4] 2> 678854 T3090 C958 P47550 oasc.SolrCore.execute [collection1] webapp=/yuf/v path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=segments_2&wt=filestream} status=0 QTime=0
[junit4:junit4] 2> 678854 T3089 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 678855 T3129 C957 P40781 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 678856 T3129 C957 P40781 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 678856 T3129 C957 P40781 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 678857 T3129 C957 P40781 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@39cac026 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4653a9a3),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@39cac026 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4653a9a3),segFN=segments_2,generation=2}
[junit4:junit4] 2> 678857 T3129 C957 P40781 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 678858 T3129 C957 P40781 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 678858 T3129 C957 P40781 oass.SolrIndexSearcher.<init> Opening Searcher@a792d9f6 main
[junit4:junit4] 2> 678859 T3128 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@a792d9f6 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 678859 T3129 C957 P40781 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty3/index.20130605165549659 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty3/index.20130605165549659;done=true>>]
[junit4:junit4] 2> 678860 T3129 C957 P40781 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty3/index.20130605165549659
[junit4:junit4] 2> 678860 T3129 C957 P40781 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty3/index.20130605165549659
[junit4:junit4] 2> 678860 T3089 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 678860 T3129 C957 P40781 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 678861 T3129 C957 P40781 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 678862 T3129 C957 P40781 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 678862 T3129 C957 P40781 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 678862 T3089 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 678863 T3089 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 678863 T3129 C957 P40781 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 678863 T3089 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 678865 T3089 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 678865 T3089 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 678866 T3089 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 678867 T3089 oasc.SolrCore.<init> [onenodecollectioncore] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1370411733819/onenodecollectioncore/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1370411730425/onenodecollection/
[junit4:junit4] 2> 678867 T3089 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5cc50aa0
[junit4:junit4] 2> 678868 T3089 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 678869 T3089 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1370411730425/onenodecollection
[junit4:junit4] 2> 678870 T3089 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1370411730425/onenodecollection/index/
[junit4:junit4] 2> 678870 T3089 oasc.SolrCore.initIndex WARN [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1370411730425/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 678871 T3089 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1370411730425/onenodecollection/index
[junit4:junit4] 2> 678873 T3089 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4bb05537 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4ed8aaa),segFN=segments_1,generation=1}
[junit4:junit4] 2> 678874 T3089 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 678876 T3089 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 678877 T3089 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 678877 T3089 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 678878 T3089 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 678879 T3089 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 678880 T3089 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 678880 T3089 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 678881 T3089 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 678882 T3089 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 678883 T3089 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 678885 T3089 oass.SolrIndexSearcher.<init> Opening Searcher@3d004d8e main
[junit4:junit4] 2> 678886 T3089 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1370411730425/onenodecollection/tlog
[junit4:junit4] 2> 678887 T3089 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 678888 T3089 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 678891 T3150 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@3d004d8e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 678893 T3089 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> 679674 T3075 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 679675 T3075 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:60986/yuf/v",
[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:60986_yuf%2Fv",
[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> 679678 T3075 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:40781/yuf/v",
[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:40781_yuf%2Fv",
[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> 679680 T3075 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:47550/yuf/v",
[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:47550_yuf%2Fv",
[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> 679680 T3075 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4] 2> 679680 T3075 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 679783 T3110 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> 679783 T3126 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 679783 T3094 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> 679783 T3081 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> 679783 T3143 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 679783 T3074 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> 679894 T3089 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4] 2> 679895 T3089 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:47550/yuf/v collection:onenodecollection shard:shard1
[junit4:junit4] 2> 679896 T3089 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4] 2> 679900 T3089 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 679902 T3089 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 679902 T3089 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 679903 T3089 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:47550/yuf/v/onenodecollectioncore/
[junit4:junit4] 2> 679903 T3089 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 679904 T3089 oasc.SyncStrategy.syncToMe http://127.0.0.1:47550/yuf/v/onenodecollectioncore/ has no replicas
[junit4:junit4] 2> 679904 T3089 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:47550/yuf/v/onenodecollectioncore/
[junit4:junit4] 2> 679905 T3089 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4] 2> 680435 T3104 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 680436 T3104 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:60986_yuf%252Fv&core=collection1} status=0 QTime=2002
[junit4:junit4] 2> 681288 T3075 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 681318 T3126 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 681318 T3094 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> 681319 T3143 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 681319 T3081 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> 681318 T3074 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> 681318 T3110 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> 681364 T3089 oasc.ZkController.register We are http://127.0.0.1:47550/yuf/v/onenodecollectioncore/ and leader is http://127.0.0.1:47550/yuf/v/onenodecollectioncore/
[junit4:junit4] 2> 681364 T3089 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:47550/yuf/v
[junit4:junit4] 2> 681365 T3089 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 681366 T3089 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4] 2> 681367 T3089 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 681368 T3089 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1370411730425/onenodecollection&action=CREATE&version=2&numShards=1&name=onenodecollectioncore&wt=javabin&roles=none&collection=onenodecollection} status=0 QTime=2928
[junit4:junit4] 2> 681369 T3052 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4] 2> 681370 T3052 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 682372 T3052 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C959 name=collection1 org.apache.solr.core.SolrCore@223abfa2 url=http://127.0.0.1:60986/yuf/v/collection1 node=127.0.0.1:60986_yuf%2Fv C959_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:60986/yuf/v, state=recovering, node_name=127.0.0.1:60986_yuf%2Fv, collection=collection1, shard=shard2, core=collection1}
[junit4:junit4] 2> 682437 T3146 C959 P60986 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:50373/yuf/v/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 682438 T3146 C959 P60986 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:60986/yuf/v START replicas=[http://127.0.0.1:50373/yuf/v/collection1/] nUpdates=100
[junit4:junit4] 2> 682438 T3146 C959 P60986 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 682438 T3146 C959 P60986 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 682439 T3146 C959 P60986 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 682439 T3146 C959 P60986 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 682439 T3146 C959 P60986 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 682440 T3146 C959 P60986 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:50373/yuf/v/collection1/. core=collection1
[junit4:junit4] 2> 682440 T3146 C959 P60986 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C960 name=collection1 org.apache.solr.core.SolrCore@8c35287 url=http://127.0.0.1:50373/yuf/v/collection1 node=127.0.0.1:50373_yuf%2Fv C960_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:50373/yuf/v, state=active, node_name=127.0.0.1:50373_yuf%2Fv, collection=collection1, shard=shard2, core=collection1, leader=true}
[junit4:junit4] 2> 682446 T3103 C960 P50373 oasc.SolrCore.execute [collection1] webapp=/yuf/v path=/get params={getVersions=100&qt=/get&distrib=false&version=2&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 682450 T3104 C960 P50373 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 682452 T3104 C960 P50373 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@42129c81 lockFactory=org.apache.lucene.store.NativeFSLockFactory@fdda1546),segFN=segments_1,generation=1}
[junit4:junit4] 2> 682452 T3104 C960 P50373 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 682453 T3104 C960 P50373 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@42129c81 lockFactory=org.apache.lucene.store.NativeFSLockFactory@fdda1546),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@42129c81 lockFactory=org.apache.lucene.store.NativeFSLockFactory@fdda1546),segFN=segments_2,generation=2}
[junit4:junit4] 2> 682454 T3104 C960 P50373 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 682455 T3104 C960 P50373 oass.SolrIndexSearcher.<init> Opening Searcher@fea59d69 realtime
[junit4:junit4] 2> 682456 T3104 C960 P50373 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 682456 T3104 C960 P50373 oasup.LogUpdateProcessor.finish [collection1] webapp=/yuf/v path=/update params={softCommit=false&commit_end_point=true&commit=true&version=2&waitSearcher=true&wt=javabin&openSearcher=false} {commit=} 0 6
[junit4:junit4] 2> 682457 T3146 C959 P60986 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 682457 T3146 C959 P60986 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 682459 T3103 C960 P50373 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 682460 T3103 C960 P50373 oasc.SolrCore.execute [collection1] webapp=/yuf/v path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=2
[junit4:junit4] 2> 682460 T3146 C959 P60986 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 682460 T3146 C959 P60986 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 682461 T3146 C959 P60986 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 682463 T3106 C960 P50373 oasc.SolrCore.execute [collection1] webapp=/yuf/v path=/replication params={qt=/replication&version=2&generation=2&command=filelist&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 682463 T3146 C959 P60986 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 682464 T3146 C959 P60986 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty4/index.20130605165553271
[junit4:junit4] 2> 682464 T3146 C959 P60986 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@8f440d9c lockFactory=org.apache.lucene.store.NativeFSLockFactory@e13eb384) fullCopy=false
[junit4:junit4] 2> 682466 T3104 C960 P50373 oasc.SolrCore.execute [collection1] webapp=/yuf/v path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=segments_2&wt=filestream} status=0 QTime=0
[junit4:junit4] 2> 682467 T3146 C959 P60986 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 682468 T3146 C959 P60986 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 682468 T3146 C959 P60986 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 682469 T3146 C959 P60986 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6fa51399 lockFactory=org.apache.lucene.store.NativeFSLockFactory@ef8ed41b),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6fa51399 lockFactory=org.apache.lucene.store.NativeFSLockFactory@ef8ed41b),segFN=segments_2,generation=2}
[junit4:junit4] 2> 682470 T3146 C959 P60986 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 682470 T3146 C959 P60986 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 682470 T3146 C959 P60986 oass.SolrIndexSearcher.<init> Opening Searcher@e2699f41 main
[junit4:junit4] 2> 682471 T3145 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e2699f41 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 682472 T3146 C959 P60986 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty4/index.20130605165553271 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty4/index.20130605165553271;done=true>>]
[junit4:junit4] 2> 682472 T3146 C959 P60986 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty4/index.20130605165553271
[junit4:junit4] 2> 682472 T3146 C959 P60986 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty4/index.20130605165553271
[junit4:junit4] 2> 682472 T3146 C959 P60986 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 682473 T3146 C959 P60986 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 682473 T3146 C959 P60986 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 682473 T3146 C959 P60986 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 682475 T3146 C959 P60986 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 682824 T3075 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 682825 T3075 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:47550/yuf/v",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:47550_yuf%2Fv_onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:47550_yuf%2Fv",
[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> 682828 T3075 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:60986/yuf/v",
[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:60986_yuf%2Fv",
[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> 682831 T3110 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> 682831 T3074 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> 682831 T3126 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 682832 T3143 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 682831 T3081 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> 682831 T3094 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> 683373 T3052 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 683374 T3052 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4] 2> 683375 T3052 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 683384 T3052 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 683385 T3154 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@30eeb15d name:ZooKeeperConnection Watcher:127.0.0.1:41252 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 683386 T3052 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 683428 T3052 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 51682
[junit4:junit4] 2> 683428 T3052 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=-1500701346
[junit4:junit4] 2> 684337 T3075 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 684338 T3075 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:51682/yuf/v",
[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:51682_yuf%2Fv",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 684342 T3074 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> 684343 T3126 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 684342 T3094 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> 684343 T3143 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 684342 T3110 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> 685430 T3052 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 685431 T3052 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 685433 T3052 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@c1f41ee0
[junit4:junit4] 2> 685441 T3052 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> 685442 T3052 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 685443 T3052 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 685443 T3052 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 685444 T3052 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 685444 T3052 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 685445 T3052 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/control/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/control/data/index;done=false>>]
[junit4:junit4] 2> 685445 T3052 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/control/data/index
[junit4:junit4] 2> 685446 T3052 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/control/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/control/data;done=false>>]
[junit4:junit4] 2> 685447 T3052 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/control/data
[junit4:junit4] 2> 685448 T3075 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89811303165394947-127.0.0.1:51682_yuf%2Fv-n_0000000000) am no longer a leader.
[junit4:junit4] 2> 685449 T3126 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> 685449 T3143 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> 685449 T3110 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> 685449 T3074 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 685450 T3126 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 685450 T3074 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> 685451 T3110 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 685451 T3143 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 685451 T3074 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 685454 T3094 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 685456 T3094 oasc.Overseer.start Overseer (id=89811303165394950-127.0.0.1:47550_yuf%2Fv-n_0000000001) starting
[junit4:junit4] 2> 685459 T3094 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 685460 T3156 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 685460 T3155 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 685460 T3094 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> 685461 T3155 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 685462 T3155 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:51682/yuf/v",
[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:51682_yuf%2Fv",
[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> 685465 T3126 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> 685465 T3143 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> 685465 T3110 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> 685467 T3094 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> 685469 T3052 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/yuf/v,null}
[junit4:junit4] 2> 685522 T3052 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 47550
[junit4:junit4] 2> 685524 T3052 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1098941372
[junit4:junit4] 2> 686969 T3155 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 686971 T3155 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:47550/yuf/v",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:47550_yuf%2Fv_onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:47550_yuf%2Fv",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"onenodecollectioncore"}
[junit4:junit4] 2> 686975 T3155 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:47550/yuf/v",
[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:47550_yuf%2Fv",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 686982 T3126 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> 686983 T3094 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> 686983 T3143 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> 686982 T3110 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> 688527 T3052 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 688528 T3052 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 688531 T3052 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> 688533 T3052 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@b780d6c4
[junit4:junit4] 2> 688541 T3052 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> 688542 T3052 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 688544 T3052 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 688545 T3052 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 688548 T3052 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 688549 T3052 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 688550 T3052 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty1/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty1/index;done=false>>]
[junit4:junit4] 2> 688552 T3052 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty1/index
[junit4:junit4] 2> 688554 T3052 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty1 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty1;done=false>>]
[junit4:junit4] 2> 688555 T3052 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty1
[junit4:junit4] 2> 688556 T3052 oasc.SolrCore.close [onenodecollectioncore] CLOSING SolrCore org.apache.solr.core.SolrCore@df01af5c
[junit4:junit4] 2> 688564 T3052 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> 688565 T3052 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 688565 T3052 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 688566 T3052 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 688567 T3052 oasc.SolrCore.closeSearcher [onenodecollectioncore] Closing main searcher on request.
[junit4:junit4] 2> 688567 T3052 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 688568 T3052 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1370411730425/onenodecollection [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1370411730425/onenodecollection;done=false>>]
[junit4:junit4] 2> 688569 T3052 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1370411730425/onenodecollection
[junit4:junit4] 2> 688569 T3052 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1370411730425/onenodecollection/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1370411730425/onenodecollection/index;done=false>>]
[junit4:junit4] 2> 688570 T3052 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1370411730425/onenodecollection/index
[junit4:junit4] 2> 688571 T3155 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89811303165394950-127.0.0.1:47550_yuf%2Fv-n_0000000001) am no longer a leader.
[junit4:junit4] 2> 688571 T3126 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> 688572 T3143 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> 688572 T3094 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 688573 T3094 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> 688573 T3094 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 688573 T3143 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 688573 T3110 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 688574 T3126 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 688576 T3126 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 688576 T3110 oasc.Overseer.start Overseer (id=89811303165394952-127.0.0.1:50373_yuf%2Fv-n_0000000002) starting
[junit4:junit4] 2> 688578 T3126 oasc.ShardLeaderElectionContext.shouldIBeLeader Checking if I should try and be the leader.
[junit4:junit4] 2> 688578 T3126 oasc.ShardLeaderElectionContext.shouldIBeLeader My last published State was Active, it's okay to be the leader.
[junit4:junit4] 2> 688579 T3126 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 688579 T3126 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:40781/yuf/v/collection1/
[junit4:junit4] 2> 688579 T3126 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 688580 T3126 oasc.SyncStrategy.syncToMe http://127.0.0.1:40781/yuf/v/collection1/ has no replicas
[junit4:junit4] 2> 688580 T3126 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:40781/yuf/v/collection1/
[junit4:junit4] 2> 688580 T3110 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> 688580 T3158 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 688580 T3126 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 688582 T3110 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 688583 T3157 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 688584 T3157 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 688585 T3052 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/yuf/v,null}
[junit4:junit4] 2> 688586 T3157 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:47550/yuf/v",
[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:47550_yuf%2Fv",
[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> 688589 T3157 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:47550/yuf/v",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:47550_yuf%2Fv_onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:47550_yuf%2Fv",
[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> 688598 T3126 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> 688598 T3143 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> 688598 T3110 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> 688636 T3052 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 50373
[junit4:junit4] 2> 688637 T3052 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=882914814
[junit4:junit4] 2> 689639 T3052 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 689640 T3052 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 689641 T3052 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@8c35287
[junit4:junit4] 2> 689645 T3052 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> 689645 T3052 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 689646 T3052 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 689647 T3052 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 689648 T3052 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 689648 T3052 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 689649 T3052 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty2 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty2;done=false>>]
[junit4:junit4] 2> 689649 T3052 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty2
[junit4:junit4] 2> 689650 T3052 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty2/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty2/index;done=false>>]
[junit4:junit4] 2> 689650 T3052 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty2/index
[junit4:junit4] 2> 689651 T3157 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89811303165394952-127.0.0.1:50373_yuf%2Fv-n_0000000002) am no longer a leader.
[junit4:junit4] 2> 689652 T3126 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> 689652 T3110 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> 689653 T3110 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 689653 T3143 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 689653 T3110 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 689654 T3126 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 689655 T3143 oasc.ShardLeaderElectionContext.shouldIBeLeader Checking if I should try and be the leader.
[junit4:junit4] 2> 689655 T3126 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 689655 T3143 oasc.ShardLeaderElectionContext.shouldIBeLeader My last published State was Active, it's okay to be the leader.
[junit4:junit4] 2> 689656 T3143 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 689656 T3143 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:60986/yuf/v/collection1/
[junit4:junit4] 2> 689657 T3126 oasc.Overseer.start Overseer (id=89811303165394954-127.0.0.1:40781_yuf%2Fv-n_0000000003) starting
[junit4:junit4] 2> 689657 T3143 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:60986/yuf/v START replicas=[http://127.0.0.1:50373/yuf/v/collection1/] nUpdates=100
[junit4:junit4] 2> 689657 T3143 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:60986/yuf/v DONE. We have no versions. sync failed.
[junit4:junit4] 2> 689658 T3143 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 689659 T3143 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> 689659 T3143 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:60986/yuf/v/collection1/
[junit4:junit4] 2> 689659 T3143 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 689660 T3161 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 689660 T3160 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 689662 T3160 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 689663 T3160 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50373/yuf/v",
[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:50373_yuf%2Fv",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 689664 T3143 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> 689665 T3052 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/yuf/v,null}
[junit4:junit4] 2> 689665 T3143 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 689668 T3160 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:50373/yuf/v",
[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:50373_yuf%2Fv",
[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> 689675 T3143 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> 689676 T3126 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> 689716 T3052 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 40781
[junit4:junit4] 2> 689717 T3052 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1568612555
[junit4:junit4] 2> 690719 T3052 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 690719 T3052 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 690722 T3052 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@ad115204
[junit4:junit4] 2> 690726 T3052 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> 690727 T3052 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 690728 T3052 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 690729 T3052 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 690730 T3052 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 690730 T3052 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 690731 T3052 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty3/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty3/index;done=false>>]
[junit4:junit4] 2> 690732 T3052 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty3/index
[junit4:junit4] 2> 690732 T3052 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty3 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty3;done=false>>]
[junit4:junit4] 2> 690733 T3052 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty3
[junit4:junit4] 2> 690734 T3160 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89811303165394954-127.0.0.1:40781_yuf%2Fv-n_0000000003) am no longer a leader.
[junit4:junit4] 2> 690734 T3126 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> 690735 T3126 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 690735 T3126 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 690735 T3143 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 690737 T3143 oasc.Overseer.start Overseer (id=89811303165394956-127.0.0.1:60986_yuf%2Fv-n_0000000004) starting
[junit4:junit4] 2> 690740 T3143 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> 690740 T3163 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 690742 T3162 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 690742 T3143 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4:junit4] 2> 690744 T3162 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 690744 T3162 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:40781/yuf/v",
[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:40781_yuf%2Fv",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 690747 T3162 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:40781/yuf/v",
[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:40781_yuf%2Fv",
[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> 690750 T3143 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> 690755 T3052 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/yuf/v,null}
[junit4:junit4] 2> 690807 T3052 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 60986
[junit4:junit4] 2> 690808 T3052 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1460132615
[junit4:junit4] 2> 691809 T3052 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 691810 T3052 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 691812 T3052 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@223abfa2
[junit4:junit4] 2> 691818 T3052 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> 691818 T3052 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 691819 T3052 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 691819 T3052 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 691820 T3052 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 691821 T3052 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 691821 T3052 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty4 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty4;done=false>>]
[junit4:junit4] 2> 691822 T3052 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty4
[junit4:junit4] 2> 691823 T3052 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty4/index;done=false>>]
[junit4:junit4] 2> 691823 T3052 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1370411730425/jetty4/index
[junit4:junit4] 2> 691824 T3162 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89811303165394956-127.0.0.1:60986_yuf%2Fv-n_0000000004) am no longer a leader.
[junit4:junit4] 2> 691825 T3143 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> 691825 T3143 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 691825 T3143 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 691845 T3052 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/yuf/v,null}
[junit4:junit4] 2> 691902 T3052 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 691903 T3052 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:41252 41252
[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":"89811303165394947-127.0.0.1:51682_yuf%2Fv-n_0000000000"}
[junit4:junit4] 1> /solr/overseer_elect/election (5)
[junit4:junit4] 1> /solr/overseer_elect/election/89811303165394956-127.0.0.1:60986_yuf%2Fv-n_0000000004 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89811303165394954-127.0.0.1:40781_yuf%2Fv-n_0000000003 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89811303165394952-127.0.0.1:50373_yuf%2Fv-n_0000000002 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89811303165394950-127.0.0.1:47550_yuf%2Fv-n_0000000001 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89811303165394947-127.0.0.1:51682_yuf%2Fv-n_0000000000 (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/89811303165394947-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:51682/yuf/v",
[junit4:junit4] 1> "node_name":"127.0.0.1:51682_yuf%2Fv",
[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/89811303165394950-2-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/89811303165394954-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/89811303165394956-5-n_0000000001 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2/election/89811303165394952-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:47550/yuf/v",
[junit4:junit4] 1> "node_name":"127.0.0.1:47550_yuf%2Fv",
[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:50373/yuf/v",
[junit4:junit4] 1> "node_name":"127.0.0.1:50373_yuf%2Fv",
[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/89811303165394950-127.0.0.1:47550_yuf%2Fv_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:47550/yuf/v",
[junit4:junit4] 1> "node_name":"127.0.0.1:47550_yuf%2Fv",
[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:60986_yuf%2Fv (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:47550_yuf%2Fv (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:40781_yuf%2Fv (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:50373_yuf%2Fv (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:51682_yuf%2Fv (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:51682/yuf/v",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:51682_yuf%2Fv",
[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:47550_yuf%2Fv_onenodecollectioncore":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:47550/yuf/v",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:47550_yuf%2Fv",
[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:47550/yuf/v",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:47550_yuf%2Fv",
[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:40781/yuf/v",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:40781_yuf%2Fv",
[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:50373/yuf/v",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:50373_yuf%2Fv",
[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:60986/yuf/v",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:60986_yuf%2Fv",
[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=73BF5CAB17741375 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=mr_IN -Dtests.timezone=Asia/Sakhalin -Dtests.file.encoding=US-ASCII
[junit4:junit4] ERROR 32.3s J0 | BasicDistributedZk2Test.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:50373/yuf/v/onenodecollectioncore returned non ok status:404, message:Can not find: /yuf/v/onenodecollectioncore/update
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([73BF5CAB17741375:F259D2B3602B7349]: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> 691927 T3052 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 32319 T3051 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {}, docValues:{}, sim=DefaultSimilarity, locale=mr_IN, timezone=Asia/Sakhalin
[junit4:junit4] 2> NOTE: Linux 3.2.0-45-generic x86/IBM Corporation 1.7.0 (32-bit)/cpus=8,threads=2,free=41852448,total=203292672
[junit4:junit4] 2> NOTE: All tests run in this JVM: [PolyFieldTest, TestPluginEnable, TestGroupingSearch, TestUniqueKeyFieldResource, TestClassNameShortening, TestCharFilters, OverseerTest, TestStressVersions, UnloadDistributedZkTest, TestFieldCollectionResource, ChaosMonkeyNothingIsSafeTest, LoggingHandlerTest, DistributedTermsComponentTest, BinaryUpdateRequestHandlerTest, SliceStateTest, SolrCoreTest, TestTrie, TestSearchPerf, SyncSliceTest, TestExtendedDismaxParser, TestLRUCache, TestFunctionQuery, WordBreakSolrSpellCheckerTest, SuggesterFSTTest, DirectSolrConnectionTest, TestFuzzyAnalyzedSuggestions, TestSolrQueryParser, IndexSchemaTest, TestXIncludeConfig, UUIDFieldTest, TestFastLRUCache, PrimUtilsTest, FieldMutatingUpdateProcessorTest, PreAnalyzedFieldTest, TestPerFieldSimilarity, TestPseudoReturnFields, LeaderElectionTest, TestSchemaResource, SpellingQueryConverterTest, TestSolrIndexConfig, ReturnFieldsTest, StatelessScriptUpdateProcessorFactoryTest, CoreAdminHandlerTest, BadCopyFieldTest, UpdateRequestProcessorFactoryTest, TestWriterPerf, SearchHandlerTest, MBeansHandlerTest, ShowFileRequestHandlerTest, SoftAutoCommitTest, CacheHeaderTest, ZkCLITest, OverseerCollectionProcessorTest, TestRandomDVFaceting, TestSweetSpotSimilarityFactory, SOLR749Test, LukeRequestHandlerTest, TestSolrDeletionPolicy1, FileBasedSpellCheckerTest, RAMDirectoryFactoryTest, SpatialFilterTest, DistributedSpellCheckComponentTest, CircularListTest, DateFieldTest, TestReversedWildcardFilterFactory, SolrTestCaseJ4Test, PluginInfoTest, TestRealTimeGet, TestReplicationHandler, ResourceLoaderTest, BadComponentTest, TestValueSourceCache, BasicDistributedZkTest, BasicDistributedZk2Test]
[junit4:junit4] Completed on J0 in 32.84s, 1 test, 1 error <<< FAILURES!
[...truncated 466 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:380: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:373: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:437: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1240: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:884: There were test failures: 296 suites, 1235 tests, 1 error, 14 ignored (8 assumptions)
Total time: 41 minutes 23 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